"unauthorized” error reported when access web server

Tan Dehui dehuitan1988 at hotmail.com
Wed Dec 1 12:28:24 AEDT 2021


An “unauthorized” error was reported when I accessed the Web server through the browser.  The logs is attached below.
By capturing network data, I found that no more messages are sent after the Web Server and Web Client send Hello messages to each other.
Further, through debugging I suspect that the authentication algorithm might be a bit of a problem.

LOG:
…
Feb 12 17:17:36 zcu102-zynqmp systemd[1]: Starting Phosphor User Manager...
Feb 12 17:17:36 zcu102-zynqmp systemd[1]: Started Phosphor sysfs LED controller.
Feb 12 17:17:36 zcu102-zynqmp systemd[1]: Started Phosphor sysfs LED controller.
Feb 12 17:17:36 zcu102-zynqmp nslcd[354]: [8b4567] <group="priv-noaccess"> failed to bind to LDAP server ldap://127.0.0.1/: Can't contact LDAP server: Transport endpoint is not connected
Feb 12 17:17:36 zcu102-zynqmp nslcd[354]: [8b4567] <group="priv-noaccess"> no available LDAP server found, sleeping 1 seconds
Feb 12 17:17:36 zcu102-zynqmp systemd[1]: Finished Load/Save Random Seed.
Feb 12 17:17:36 zcu102-zynqmp bmcweb[336]: Checking certs in file /etc/ssl/certs/https/server.pem
Feb 12 17:17:36 zcu102-zynqmp bmcweb[336]: Error in verifying signature, regenerating
Feb 12 17:17:36 zcu102-zynqmp bmcweb[336]: Generating new keys
Feb 12 17:17:36 zcu102-zynqmp bmcweb[336]: Generating EC key
Feb 12 17:17:36 zcu102-zynqmp systemd[1]: Started Name Service Cache Daemon.
Feb 12 17:17:36 zcu102-zynqmp bmcweb[336]: Generating x509 Certificate
Feb 12 17:17:36 zcu102-zynqmp systemd[1]: Started LDAP daemon.
Feb 12 17:17:36 zcu102-zynqmp systemd[1]: obmc-phosphor-sysd.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 17:17:36 zcu102-zynqmp systemd[1]: obmc-phosphor-sysd.service: Failed with result 'exit-code'.
Feb 12 17:17:36 zcu102-zynqmp systemd[1]: Started OpenBMC ipKVM daemon.
Feb 12 17:17:36 zcu102-zynqmp systemd[1]: Finished Permit User Sessions.
Feb 12 17:17:36 zcu102-zynqmp systemd[1]: Started Phosphor Log Manager.
Feb 12 17:17:36 zcu102-zynqmp avahi-daemon[394]: Found user 'avahi' (UID 998) and group 'avahi' (GID 998).
Feb 12 17:17:36 zcu102-zynqmp nslcd[354]: [7b23c6] <group/member="avahi"> failed to bind to LDAP server ldap://127.0.0.1/: Can't contact LDAP server: Transport endpoint is not connected
Feb 12 17:17:36 zcu102-zynqmp nslcd[354]: [7b23c6] <group/member="avahi"> no available LDAP server found, sleeping 1 seconds
Feb 12 17:17:36 zcu102-zynqmp obmc-ikvm[392]: Failed to open input device
Feb 12 17:17:36 zcu102-zynqmp audit[392]: ANOM_ABEND auid=4294967295 uid=0 gid=0 ses=4294967295 pid=392 comm="obmc-ikvm" exe="/usr/bin/obmc-ikvm" sig=6 res=1
Feb 12 17:17:36 zcu102-zynqmp obmc-ikvm[392]: Failed to open a file
Feb 12 17:17:36 zcu102-zynqmp obmc-ikvm[392]: terminate called after throwing an instance of 'sdbusplus::xyz::openbmc_project::Common::File::Error::Open'
Feb 12 17:17:36 zcu102-zynqmp obmc-ikvm[392]:   what():  xyz.openbmc_project.Common.File.Error.Open: Failed to open a file
Feb 12 17:17:36 zcu102-zynqmp systemd[1]: Started Phosphor LDAP privilege mapper.
Feb 12 17:17:36 zcu102-zynqmp kernel: audit: type=1701 audit(1613150256.355:2): auid=4294967295 uid=0 gid=0 ses=4294967295 pid=392 comm="obmc-ikvm" exe="/usr/bin/obmc-ikvm" sig=6 res=1
Feb 12 17:17:36 zcu102-zynqmp phosphor-certificate-manager[363]: Writing private key to file
…
Feb 12 17:17:37 zcu102-zynqmp sh[339]: Fingerprint: sha1!! 31:c8:95:38:53:b4:7d:08:94:c9:44:1b:dd:ae:16:71:cc:ec:fd:d1
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Finished SSH Key Generation.
Feb 12 17:17:37 zcu102-zynqmp systemd[415]: systemd-coredump at 0-395-0.service: ProtectHostname=yes is configured, but the kernel does not support UTS namespaces, ignoring namespace setup.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Started Wait for /xyz/openbmc_project/control/host0/boot/one_time.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Started Wait for /xyz/openbmc_project/control/host0/boot.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: start-ipkvm.service: Main process exited, code=dumped, status=6/ABRT
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: start-ipkvm.service: Failed with result 'core-dump'.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Started Wait for /xyz/openbmc_project/control/host0/power_restore_policy.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Started Wait for /xyz/openbmc_project/control/host0/restriction_mode.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Started Wait for /xyz/openbmc_project/led/groups/bmc_booted.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Started Wait for /xyz/openbmc_project/time/sync_method.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Started Phosphor LED Group Management Daemon.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Started Phosphor Ldap config updater.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Started Phosphor SNMP conf Manager.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Started Phosphor Network Manager.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Started OpenBMC Software Update Manager.
Feb 12 17:17:37 zcu102-zynqmp phosphor-chassis-state-manager[414]: Initial Chassis State will be Off
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Started Phosphor Chassis State Manager.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Started Wait for /xyz/openbmc_project/state/chassis0.
Feb 12 17:17:37 zcu102-zynqmp nslcd[354]: [8b4567] <group="priv-noaccess"> failed to bind to LDAP server ldap://127.0.0.1/: Can't contact LDAP server: Transport endpoint is not connected
Feb 12 17:17:37 zcu102-zynqmp nslcd[354]: [8b4567] <group="priv-noaccess"> no available LDAP server found, sleeping 1 seconds
Feb 12 17:17:37 zcu102-zynqmp phosphor-bmc-state-manager[413]: Setting the BMCState field
Feb 12 17:17:37 zcu102-zynqmp phosphor-bmc-state-manager[413]: Setting the BMCState field
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Starting Wait for /xyz/openbmc_project/led/groups...
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Starting Phosphor Inband IPMI...
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Stopping Network Service...
Feb 12 17:17:37 zcu102-zynqmp nscd[341]: 341 ignored inotify event for `/etc/resolv.conf` (file exists)
Feb 12 17:17:37 zcu102-zynqmp nscd[341]: 341 ignored inotify event for `/etc/resolv.conf` (file exists)
Feb 12 17:17:37 zcu102-zynqmp systemd-timesyncd[233]: Network configuration changed, trying to establish connection.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Condition check resulted in Platform Persistent Storage Archival being skipped.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Starting Phosphor Version Software Manager...
Feb 12 17:17:37 zcu102-zynqmp ipmid[426]: JSON file not found
Feb 12 17:17:37 zcu102-zynqmp ipmid[426]: JSON file not found
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Started Wait for /xyz/openbmc_project/led/groups.
Feb 12 17:17:37 zcu102-zynqmp systemd-timesyncd[233]: Network configuration changed, trying to establish connection.
Feb 12 17:17:37 zcu102-zynqmp nslcd[354]: [7b23c6] <group/member="avahi"> failed to bind to LDAP server ldap://127.0.0.1/: Can't contact LDAP server: Transport endpoint is not connected
Feb 12 17:17:37 zcu102-zynqmp nslcd[354]: [7b23c6] <group/member="avahi"> no available LDAP server found, sleeping 1 seconds
Feb 12 17:17:37 zcu102-zynqmp audit[426]: ANOM_ABEND auid=4294967295 uid=0 gid=0 ses=4294967295 pid=426 comm="ipmid" exe="/usr/bin/ipmid" sig=11 res=1
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: systemd-networkd.service: Succeeded.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Stopped Network Service.
Feb 12 17:17:37 zcu102-zynqmp kernel: audit: type=1701 audit(1613150257.355:3): auid=4294967295 uid=0 gid=0 ses=4294967295 pid=426 comm="ipmid" exe="/usr/bin/ipmid" sig=11 res=1
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: obmc-phosphor-sysd.service: Scheduled restart job, restart counter is at 1.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Started Phosphor BMC State Manager.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Started Phosphor Inband IPMI.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Started Phosphor Version Software Manager.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Condition check resulted in Kernel Trace File System being skipped.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Condition check resulted in Create list of static device nodes for the current kernel being skipped.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Stopped Phosphor System Manager.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Condition check resulted in File System Check on Root Device being skipped.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Condition check resulted in Load Kernel Modules being skipped.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Condition check resulted in FUSE Control File System being skipped.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Starting Network Service...
Feb 12 17:17:37 zcu102-zynqmp nslcd[354]: [3c9869] <group/member="systemd-network"> failed to bind to LDAP server ldap://127.0.0.1/: Can't contact LDAP server: Transport endpoint is not connected
Feb 12 17:17:37 zcu102-zynqmp nslcd[354]: [3c9869] <group/member="systemd-network"> no available LDAP server found, sleeping 1 seconds
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Condition check resulted in Platform Persistent Storage Archival being skipped.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Condition check resulted in Bind mount volatile /var/cache being skipped.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Condition check resulted in Bind mount volatile /var/lib being skipped.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Condition check resulted in Bind mount volatile /var/spool being skipped.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Condition check resulted in Bind mount volatile /srv being skipped.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Condition check resulted in Commit a transient machine-id on disk being skipped.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Started FRU Fault monitor service.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Started Phosphor System Manager.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Started Network IPMI daemon.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Condition check resulted in Check Host0 status on BMC reset being skipped.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Reached target Host0 running after reset.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Condition check resulted in Start host0 running after BMC reset being skipped.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Starting Phosphor Host State Manager...
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Started Process Core Dump (PID 430/UID 0).
Feb 12 17:17:37 zcu102-zynqmp systemd[437]: systemd-coredump at 1-430-0.service: PrivateNetwork=yes is configured, but the kernel does not support network namespaces, ignoring.
Feb 12 17:17:37 zcu102-zynqmp audit[435]: ANOM_ABEND auid=4294967295 uid=0 gid=0 ses=4294967295 pid=435 comm="netipmid" exe="/usr/bin/netipmid" sig=11 res=1
Feb 12 17:17:37 zcu102-zynqmp kernel: audit: type=1701 audit(1613150257.583:4): auid=4294967295 uid=0 gid=0 ses=4294967295 pid=435 comm="netipmid" exe="/usr/bin/netipmid" sig=11 res=1
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Started Process Core Dump (PID 438/UID 0).
Feb 12 17:17:37 zcu102-zynqmp obmc-phosphor-sysd[434]:   File "/usr/sbin/obmc-phosphor-sysd", line 26
Feb 12 17:17:37 zcu102-zynqmp obmc-phosphor-sysd[434]:     print "obmc-phosphor-watchdogd starting..."
Feb 12 17:17:37 zcu102-zynqmp obmc-phosphor-sysd[434]:           ^
Feb 12 17:17:37 zcu102-zynqmp obmc-phosphor-sysd[434]: SyntaxError: Missing parentheses in call to 'print'. Did you mean print("obmc-phosphor-watchdogd starting...")?
Feb 12 17:17:37 zcu102-zynqmp systemd[439]: systemd-coredump at 2-438-0.service: PrivateNetwork=yes is configured, but the kernel does not support network namespaces, ignoring.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: obmc-phosphor-sysd.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: obmc-phosphor-sysd.service: Failed with result 'exit-code'.
Feb 12 17:17:37 zcu102-zynqmp phosphor-host-state-manager[436]: Initial Host State will be Off
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Started Phosphor Host State Manager.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Started Wait for /xyz/openbmc_project/state/host0.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Starting Reboot If Enabled...
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Starting Reset host sensors...
Feb 12 17:17:37 zcu102-zynqmp phosphor-discover-system-state[441]: Host power is off, checking power policy
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Starting Phosphor Time Manager daemon...
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Finished Reboot If Enabled.
Feb 12 17:17:37 zcu102-zynqmp phosphor-timemanager[444]: Time mode is changed
Feb 12 17:17:37 zcu102-zynqmp systemd[437]: systemd-coredump at 1-430-0.service: ProtectHostname=yes is configured, but the kernel does not support UTS namespaces, ignoring namespace setup.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Condition check resulted in Kernel Trace File System being skipped.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Condition check resulted in Create list of static device nodes for the current kernel being skipped.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Condition check resulted in File System Check on Root Device being skipped.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Condition check resulted in Load Kernel Modules being skipped.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Condition check resulted in FUSE Control File System being skipped.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Condition check resulted in Platform Persistent Storage Archival being skipped.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Condition check resulted in Bind mount volatile /var/cache being skipped.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Condition check resulted in Bind mount volatile /var/lib being skipped.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Condition check resulted in Bind mount volatile /var/spool being skipped.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Condition check resulted in Bind mount volatile /srv being skipped.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Condition check resulted in Commit a transient machine-id on disk being skipped.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Starting Time & Date Service...
Feb 12 17:17:37 zcu102-zynqmp phosphor-mapper[378]: Introspect call failed with error: generic:113, No route to host on process: xyz.openbmc_project.Control.Host path: /
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: phosphor-ipmi-host.service: Main process exited, code=dumped, status=11/SEGV
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: phosphor-ipmi-host.service: Failed with result 'core-dump'.
Feb 12 17:17:37 zcu102-zynqmp systemd[439]: systemd-coredump at 2-438-0.service: ProtectHostname=yes is configured, but the kernel does not support UTS namespaces, ignoring namespace setup.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: phosphor-reset-sensor-states at 0.service: Succeeded.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Finished Reset host sensors.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Reached target Host0 (Reset Check).
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: phosphor-ipmi-net at eth0.service: Main process exited, code=dumped, status=11/SEGV
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: phosphor-ipmi-net at eth0.service: Failed with result 'core-dump'.
Feb 12 17:17:37 zcu102-zynqmp systemd[447]: systemd-timedated.service: ProtectHostname=yes is configured, but the kernel does not support UTS namespaces, ignoring namespace setup.
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Started Time & Date Service.
Feb 12 17:17:37 zcu102-zynqmp systemd-timedated[447]: Set NTP to enabled (systemd-timesyncd.service).
Feb 12 17:17:37 zcu102-zynqmp phosphor-timemanager[444]: Updated NTP setting
Feb 12 17:17:37 zcu102-zynqmp systemd[1]: Started Phosphor Time Manager daemon.
Feb 12 17:17:38 zcu102-zynqmp nslcd[354]: [8b4567] <group="priv-noaccess"> failed to bind to LDAP server ldap://127.0.0.1/: Can't contact LDAP server: Transport endpoint is not connected
Feb 12 17:17:38 zcu102-zynqmp nslcd[354]: [8b4567] <group="priv-noaccess"> no available LDAP server found, sleeping 1 seconds
Feb 12 17:17:38 zcu102-zynqmp systemd[1]: start-ipkvm.service: Scheduled restart job, restart counter is at 1.
Feb 12 17:17:38 zcu102-zynqmp systemd[1]: Condition check resulted in Kernel Trace File System being skipped.
Feb 12 17:17:38 zcu102-zynqmp systemd[1]: Condition check resulted in Create list of static device nodes for the current kernel being skipped.
Feb 12 17:17:38 zcu102-zynqmp systemd[1]: Stopped OpenBMC ipKVM daemon.
Feb 12 17:17:38 zcu102-zynqmp systemd[1]: Condition check resulted in File System Check on Root Device being skipped.
Feb 12 17:17:38 zcu102-zynqmp systemd[1]: Condition check resulted in Load Kernel Modules being skipped.
Feb 12 17:17:38 zcu102-zynqmp systemd[1]: Condition check resulted in FUSE Control File System being skipped.
Feb 12 17:17:38 zcu102-zynqmp systemd[1]: Condition check resulted in Platform Persistent Storage Archival being skipped.
Feb 12 17:17:38 zcu102-zynqmp systemd[1]: Condition check resulted in Bind mount volatile /var/cache being skipped.
Feb 12 17:17:38 zcu102-zynqmp systemd[1]: Condition check resulted in Bind mount volatile /var/lib being skipped.
Feb 12 17:17:38 zcu102-zynqmp systemd[1]: Condition check resulted in Bind mount volatile /var/spool being skipped.
Feb 12 17:17:38 zcu102-zynqmp systemd[1]: Condition check resulted in Bind mount volatile /srv being skipped.
Feb 12 17:17:38 zcu102-zynqmp systemd[1]: Condition check resulted in Commit a transient machine-id on disk being skipped.


Tan Dehui
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.ozlabs.org/pipermail/openbmc/attachments/20211201/e8665417/attachment-0001.htm>


More information about the openbmc mailing list