[RESOLVED] Multiple Daemons failing with: permission denied

[NeilMatch]

I upgraded to Centos 6.7 a few weeks ago and have had a few unexplained gremlins which a reboot has usually fixed (mysql inserts completing ok but not actually being added to table).

I have been trying to get dbmail to work (the above mysql issue) and decided to use 'procmail' instead. The procmail recipe copies a email to a mail directory and then executes a perl script, the perl script then decodes the email MIME data and then populates a sql table with the email subject, MIME, etc. As procmail executes the Perl script, the perl script executes under the procmail userid which doesn't have read authority on the file that the procmail copy process created (can't decode the MIME if I can't read the file). I was trying to code around the procmail 'permissions' issue by creating a '/etc/sudoers.d/procmail' file and giving procmail sudo authority to read files.

To cut a long story short, procmail stopped processing incoming mail messages and I started recieving 'email delivery failures' back on my email client. After trying to work out what I had done wrong in .procmailrc, I discovered that Postfix was no longer running. I issued a 'service postfix start' and Postfix starts and them terminates with: postfix/master[8964]: fatal: open lock file /var/lib/postfix/master.lock: cannot open file: Permission denied

The permissions on /var/lib/postfix/master.lock are correct: -rw-------. 1 postfix postfix 0 Sep 28 16:53 /var/lib/postfix/master.lock

I eventually did a 'shutdown -r' and two days latter, I'm thinking of rebuilding the server.

After the reboot:
Logon via SSH to my account works ok but 'chdir' to my home directory fails: permission denied (If I logon via SSH as 'root', that works ok),
Apache starts ok but 'permissioned denied' on html/php files,
ntpd starts ok but 'permission denied' on its 'drift' file,
NetworkManager is stalled trying to start something and the Centos GUI console is stuck at either the 'spinning bubble' or on 100% (white) for the progeress bar.

I have rebooted with the previous Kennel version and the issue still persists, so I guess its not the upgrade,
I have forced a filesystem check and that came back clean,
I have done a chkpw and that came back ok,
I deleted the sudoers.d/procmail file, no different,
I have tripple check selinux and it is 'disabled',
I have tripple check all file & directory permissions... all correct,
I have compared /etc/sudoers with /etc/sudoers on other working server... identical,
I have gone through my .bash_history file and I don't seem to have done anything stupid (but I think I may have).
I have also removed my .forward & .procmailrc files, no change.

I do have a samba "/" mountpoint on the server which I use the same userid for, that works ok.

The perl script that procmail executed does have a `chmod 666 $fileName` line in it but a "find / -perm 666" on the bad server and a good server produce the same results, so I don't think the perl script changed any system files in error.



kernel: vmlinuz-2.6.32-573.3.1.el6.x86_64
selinux: disabled


/var/log/messages:
Sep 30 12:13:42 edn-web-vm-n01 kernel: e1000: eth1 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: None
Sep 30 12:13:42 edn-web-vm-n01 kernel: e1000: eth2 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: None
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> NetworkManager (version 0.8.1-99.el6) is starting...
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> Read config file /etc/NetworkManager/NetworkManager.conf
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> trying to start the modem manager...
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> monitoring kernel firmware directory '/lib/firmware'.
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> Bonding/Bridging/VLAN support disabled
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: ifcfg-rh: Acquired D-Bus service com.redhat.ifcfgrh1
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> Loaded plugin ifcfg-rh: (c) 2007 - 2008 Red Hat, Inc. To report bugs please use the NetworkManager mailing list.
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> Loaded plugin keyfile: (c) 2007 - 2008 Red Hat, Inc. To report bugs please use the NetworkManager mailing list.
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: ifcfg-rh: parsing /etc/sysconfig/network-scripts/ifcfg-lo ...
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: ifcfg-rh: parsing /etc/sysconfig/network-scripts/ifcfg-eth0 ...
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: ifcfg-rh: read connection 'System eth0'
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: ifcfg-rh: parsing /etc/sysconfig/network-scripts/ifcfg-Auto_eth2 ...
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: ifcfg-rh: read connection 'Auto eth2'
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: ifcfg-rh: parsing /etc/sysconfig/network-scripts/ifcfg-Auto_eth1 ...
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: ifcfg-rh: read connection 'Auto eth1'
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> WiFi enabled by radio killswitch; enabled by state file
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> WWAN enabled by radio killswitch; enabled by state file
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> WiMAX enabled by radio killswitch; enabled by state file
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> Networking is enabled by state file
Sep 30 12:13:43 edn-web-vm-n01 kernel: 802.1Q VLAN Support v1.8 Ben Greear <greearb@candelatech.com>
Sep 30 12:13:43 edn-web-vm-n01 kernel: All bugs added by David S. Miller <davem@redhat.com>
Sep 30 12:13:43 edn-web-vm-n01 kernel: 8021q: adding VLAN 0 to HW filter on device eth1
Sep 30 12:13:43 edn-web-vm-n01 kernel: 8021q: adding VLAN 0 to HW filter on device eth2
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> (eth1): carrier is ON
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> (eth1): new Ethernet device (driver: 'e1000' ifindex: 2)
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> (eth1): exported as /org/freedesktop/NetworkManager/Devices/0
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> (eth1): now managed
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> (eth1): device state change: unmanaged -> unavailable (reason 'connection-assumed') [1 2 41]
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> (eth1): preparing device.
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> Activation (eth1) starting connection 'Auto eth1'
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: (nm-device.c:3454):nm_device_activate: runtime check failed: (priv->state == NM_DEVICE_STATE_DISCONNECTED)
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> (eth1): device state change: unavailable -> ip-config (reason 'none') [2 7 0]
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> Activation (eth1) Stage 3 of 5 (IP Configure Start) scheduled.
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> (eth2): carrier is ON
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> (eth2): new Ethernet device (driver: 'e1000' ifindex: 3)
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> (eth2): exported as /org/freedesktop/NetworkManager/Devices/1
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> (eth2): now managed
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> (eth2): device state change: unmanaged -> unavailable (reason 'connection-assumed') [1 2 41]
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> (eth2): preparing device.
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> Activation (eth2) starting connection 'Auto eth2'
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: (nm-device.c:3454):nm_device_activate: runtime check failed: (priv->state == NM_DEVICE_STATE_DISCONNECTED)
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> (eth2): device state change: unavailable -> ip-config (reason 'none') [2 7 0]
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> Activation (eth2) Stage 3 of 5 (IP Configure Start) scheduled.
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> Trying to start the supplicant...
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> Activation (eth1) Stage 3 of 5 (IP Configure Start) started...
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> Activation (eth1) Stage 4 of 5 (IP4 Configure Get) scheduled...
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> Activation (eth1) Stage 3 of 5 (IP Configure Start) complete.
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> Activation (eth2) Stage 3 of 5 (IP Configure Start) started...
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> Activation (eth2) Stage 4 of 5 (IP4 Configure Get) scheduled...
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> Activation (eth2) Stage 3 of 5 (IP Configure Start) complete.
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> Activation (eth1) Stage 4 of 5 (IP4 Configure Get) started...
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> Activation (eth1) Stage 5 of 5 (IP Configure Commit) scheduled...
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> Activation (eth1) Stage 4 of 5 (IP4 Configure Get) complete.
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> Activation (eth2) Stage 4 of 5 (IP4 Configure Get) started...
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> Activation (eth2) Stage 5 of 5 (IP Configure Commit) scheduled...
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> Activation (eth2) Stage 4 of 5 (IP4 Configure Get) complete.
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> Activation (eth1) Stage 5 of 5 (IP Configure Commit) started...
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> (eth1): device state change: ip-config -> activated (reason 'none') [7 8 0]
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> Policy set 'Auto eth1' (eth1) as default for IPv4 routing and DNS.
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> Activation (eth1) successful, device activated.
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> Activation (eth1) Stage 5 of 5 (IP Configure Commit) complete.
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> Activation (eth2) Stage 5 of 5 (IP Configure Commit) started...
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> Policy set 'Auto eth1' (eth1) as default for IPv4 routing and DNS.
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> (eth2): device state change: ip-config -> activated (reason 'none') [7 8 0]
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> Activation (eth2) successful, device activated.
Sep 30 12:13:43 edn-web-vm-n01 NetworkManager[2202]: <info> Activation (eth2) Stage 5 of 5 (IP Configure Commit) complete.
Sep 30 12:14:03 edn-web-vm-n01 rpc.statd[2247]: Version 1.2.3 starting
Sep 30 12:14:03 edn-web-vm-n01 sm-notify[2248]: Version 1.2.3 starting
Sep 30 12:14:03 edn-web-vm-n01 rpc.statd[2247]: Failed to access local netconfig database: Netconfig database not found
Sep 30 12:14:03 edn-web-vm-n01 rpc.statd[2247]: failed to create RPC listeners, exiting
Sep 30 12:14:04 edn-web-vm-n01 kernel: RPC: Registered named UNIX socket transport module.
Sep 30 12:14:04 edn-web-vm-n01 kernel: RPC: Registered udp transport module.
Sep 30 12:14:04 edn-web-vm-n01 kernel: RPC: Registered tcp transport module.
Sep 30 12:14:04 edn-web-vm-n01 kernel: RPC: Registered tcp NFSv4.1 backchannel transport module.
Sep 30 12:14:04 edn-web-vm-n01 kernel: Slow work thread pool: Starting up
Sep 30 12:14:04 edn-web-vm-n01 kernel: Slow work thread pool: Ready
Sep 30 12:14:04 edn-web-vm-n01 kernel: FS-Cache: Loaded
Sep 30 12:14:04 edn-web-vm-n01 kernel: NFS: Registering the id_resolver key type
Sep 30 12:14:04 edn-web-vm-n01 kernel: FS-Cache: Netfs 'nfs' registered for caching
Sep 30 12:14:05 edn-web-vm-n01 acpid: starting up
Sep 30 12:14:05 edn-web-vm-n01 acpid: 1 rule loaded
Sep 30 12:14:05 edn-web-vm-n01 acpid: waiting for events: event logging is off
Sep 30 12:14:06 edn-web-vm-n01 automount[2379]: lookup_read_master: lookup(nisplus): couldn't locate nis+ table auto.master
Sep 30 12:14:07 edn-web-vm-n01 kernel: Installing knfsd (copyright (C) 1996 okir@monad.swb.de).
Sep 30 12:14:07 edn-web-vm-n01 rpc.mountd[2434]: Version 1.2.3 starting
Sep 30 12:14:07 edn-web-vm-n01 kernel: NFSD: Using /var/lib/nfs/v4recovery as the NFSv4 state recovery directory
Sep 30 12:14:07 edn-web-vm-n01 kernel: NFSD: starting 90-second grace period
Sep 30 12:14:07 edn-web-vm-n01 xinetd[2515]: xinetd Version 2.3.14 started with libwrap loadavg labeled-networking options compiled in.
Sep 30 12:14:07 edn-web-vm-n01 xinetd[2515]: Started working: 1 available service
Sep 30 12:14:07 edn-web-vm-n01 ntpd[2525]: ntpd 4.2.6p5@1.2349-o Fri Jul 24 10:56:17 UTC 2015 (1)
Sep 30 12:14:07 edn-web-vm-n01 ntpd[2526]: proto: precision = 0.098 usec
Sep 30 12:14:07 edn-web-vm-n01 ntpd[2526]: 0.0.0.0 c01d 0d kern kernel time sync enabled
Sep 30 12:14:07 edn-web-vm-n01 ntpd[2526]: Listen and drop on 0 v4wildcard 0.0.0.0 UDP 123
Sep 30 12:14:07 edn-web-vm-n01 ntpd[2526]: Listen and drop on 1 v6wildcard :: UDP 123
Sep 30 12:14:07 edn-web-vm-n01 ntpd[2526]: Listen normally on 2 lo 127.0.0.1 UDP 123
Sep 30 12:14:07 edn-web-vm-n01 ntpd[2526]: Listen normally on 3 eth1 10.245.76.161 UDP 123
Sep 30 12:14:07 edn-web-vm-n01 ntpd[2526]: Listen normally on 4 eth2 144.135.70.145 UDP 123
Sep 30 12:14:07 edn-web-vm-n01 ntpd[2526]: Listen normally on 5 eth1 fe80::20c:29ff:fe74:fff8 UDP 123
Sep 30 12:14:07 edn-web-vm-n01 ntpd[2526]: Listen normally on 6 lo ::1 UDP 123
Sep 30 12:14:07 edn-web-vm-n01 ntpd[2526]: Listen normally on 7 eth2 fe80::20c:29ff:fe74:ff02 UDP 123
Sep 30 12:14:07 edn-web-vm-n01 ntpd[2526]: Listening on routing socket on fd #24 for interface updates
Sep 30 12:14:07 edn-web-vm-n01 ntpd[2526]: 0.0.0.0 c016 06 restart
Sep 30 12:14:07 edn-web-vm-n01 ntpd[2526]: 0.0.0.0 c012 02 freq_set kernel 23.340 PPM
Sep 30 12:14:08 edn-web-vm-n01 ntpd[2526]: Deleting interface #7 eth2, fe80::20c:29ff:fe74:ff02#123, interface stats: received=0, sent=0, dropped=0, active_time=1 secs
Sep 30 12:14:08 edn-web-vm-n01 ntpd[2526]: Deleting interface #6 lo, ::1#123, interface stats: received=0, sent=0, dropped=0, active_time=1 secs
Sep 30 12:14:08 edn-web-vm-n01 ntpd[2526]: Deleting interface #5 eth1, fe80::20c:29ff:fe74:fff8#123, interface stats: received=0, sent=0, dropped=0, active_time=1 secs
Sep 30 12:14:08 edn-web-vm-n01 ntpd[2526]: 0.0.0.0 c615 05 clock_sync
Sep 30 12:14:10 edn-web-vm-n01 abrtd: Init complete, entering main loop
Sep 30 12:14:14 edn-web-vm-n01 init: vmware-tools pre-start process (3281) terminated with status 1
Sep 30 12:15:44 edn-web-vm-n01 NetworkManager[2202]: <info> Trying to start the supplicant...
Sep 30 12:17:44 edn-web-vm-n01 NetworkManager[2202]: <info> Trying to start the supplicant...
Sep 30 12:19:44 edn-web-vm-n01 NetworkManager[2202]: <info> Trying to start the supplicant...
Sep 30 12:21:44 edn-web-vm-n01 NetworkManager[2202]: <info> Trying to start the supplicant...
Sep 30 12:23:44 edn-web-vm-n01 NetworkManager[2202]: <info> Trying to start the supplicant...
Sep 30 12:25:44 edn-web-vm-n01 NetworkManager[2202]: <info> Trying to start the supplicant...
Sep 30 12:27:44 edn-web-vm-n01 NetworkManager[2202]: <info> Trying to start the supplicant...
Sep 30 12:29:44 edn-web-vm-n01 NetworkManager[2202]: <info> Trying to start the supplicant...
Sep 30 12:31:44 edn-web-vm-n01 NetworkManager[2202]: <info> Trying to start the supplicant...
Sep 30 12:33:44 edn-web-vm-n01 NetworkManager[2202]: <info> Trying to start the supplicant...
Sep 30 12:35:44 edn-web-vm-n01 NetworkManager[2202]: <info> Trying to start the supplicant...
Sep 30 12:37:44 edn-web-vm-n01 NetworkManager[2202]: <info> Trying to start the supplicant...
Sep 30 12:39:44 edn-web-vm-n01 NetworkManager[2202]: <info> Trying to start the supplicant...
Sep 30 12:41:44 edn-web-vm-n01 NetworkManager[2202]: <info> Trying to start the supplicant...
Sep 30 12:43:44 edn-web-vm-n01 NetworkManager[2202]: <info> Trying to start the supplicant...
Sep 30 12:45:44 edn-web-vm-n01 NetworkManager[2202]: <info> Trying to start the supplicant...
Sep 30 12:47:44 edn-web-vm-n01 NetworkManager[2202]: <info> Trying to start the supplicant...
Sep 30 12:49:44 edn-web-vm-n01 NetworkManager[2202]: <info> Trying to start the supplicant...
Sep 30 12:51:44 edn-web-vm-n01 NetworkManager[2202]: <info> Trying to start the supplicant...
Sep 30 12:53:44 edn-web-vm-n01 NetworkManager[2202]: <info> Trying to start the supplicant...
Sep 30 12:55:44 edn-web-vm-n01 NetworkManager[2202]: <info> Trying to start the supplicant...
Sep 30 12:57:44 edn-web-vm-n01 NetworkManager[2202]: <info> Trying to start the supplicant...
Sep 30 12:59:26 edn-web-vm-n01 abrt: detected unhandled Python exception
Sep 30 12:59:44 edn-web-vm-n01 NetworkManager[2202]: <info> Trying to start the supplicant...
Sep 30 13:01:44 edn-web-vm-n01 NetworkManager[2202]: <info> Trying to start the supplicant...
Sep 30 13:03:44 edn-web-vm-n01 NetworkManager[2202]: <info> Trying to start the supplicant...
Sep 30 13:05:44 edn-web-vm-n01 NetworkManager[2202]: <info> Trying to start the supplicant...
Sep 30 13:07:44 edn-web-vm-n01 NetworkManager[2202]: <info> Trying to start the supplicant...
Sep 30 13:09:44 edn-web-vm-n01 NetworkManager[2202]: <info> Trying to start the supplicant...
Sep 30 13:11:44 edn-web-vm-n01 NetworkManager[2202]: <info> Trying to start the supplicant...
Sep 30 13:13:44 edn-web-vm-n01 NetworkManager[2202]: <info> Trying to start the supplicant...
Sep 30 13:14:07 edn-web-vm-n01 ntpd[2526]: frequency file /var/lib/ntp/drift.TEMP: Permission denied
Sep 30 13:15:44 edn-web-vm-n01 NetworkManager[2202]: <info> Trying to start the supplicant...
Sep 30 13:17:44 edn-web-vm-n01 NetworkManager[2202]: <info> Trying to start the supplicant...
Sep 30 13:19:44 edn-web-vm-n01 NetworkManager[2202]: <info> Trying to start the supplicant...


/var/log/maillog
Sep 30 12:14:10 edn-web-vm-n01 postfix/postfix-script[3064]: starting the Postfix mail system
Sep 30 12:14:10 edn-web-vm-n01 postfix/master[3065]: fatal: open lock file /var/lib/postfix/master.lock: cannot open file: Permission denied


/var/log/httpd/error_log [ the python errorsare new ]
Wed Sep 30 09:50:57 2015] [notice] caught SIGTERM, shutting down
[Wed Sep 30 09:52:14 2015] [notice] SELinux policy enabled; httpd running as context system_u:system_r:httpd_t:s0
[Wed Sep 30 09:52:14 2015] [notice] suEXEC mechanism enabled (wrapper: /usr/sbin/suexec)
[Wed Sep 30 09:52:14 2015] [notice] Digest: generating secret for digest authentication ...
[Wed Sep 30 09:52:14 2015] [notice] Digest: done
[Wed Sep 30 09:52:16 2015] [error] avahi_client_new() failed: Access denied
[Wed Sep 30 09:52:16 2015] [notice] Apache/2.2.15 (Unix) DAV/2 PHP/5.5.29 mod_ssl/2.2.15 OpenSSL/1.0.1e-fips mod_wsgi/3.2 Python/2.6.6 configured -- resuming normal operations
Could not find platform independent libraries <prefix>
Could not find platform dependent libraries <exec_prefix>
Consider setting $PYTHONHOME to <prefix>[:<exec_prefix>]
'import site' failed; use -v for traceback
libgcc_s.so.1 must be installed for pthread_cancel to work
Could not find platform independent libraries <prefix>
Could not find platform dependent libraries <exec_prefix>
Consider setting $PYTHONHOME to <prefix>[:<exec_prefix>]
'import site' failed; use -v for traceback
Could not find platform independent libraries <prefix>
Could not find platform dependent libraries <exec_prefix>
Consider setting $PYTHONHOME to <prefix>[:<exec_prefix>]
'import site' failed; use -v for traceback
Could not find platform independent libraries <prefix>
Could not find platform dependent libraries <exec_prefix>
Consider setting $PYTHONHOME to <prefix>[:<exec_prefix>]
'import site' failed; use -v for traceback
Could not find platform independent libraries <prefix>
Could not find platform dependent libraries <exec_prefix>
Consider setting $PYTHONHOME to <prefix>[:<exec_prefix>]
'import site' failed; use -v for traceback
Could not find platform independent libraries <prefix>
Could not find platform dependent libraries <exec_prefix>
Consider setting $PYTHONHOME to <prefix>[:<exec_prefix>]
'import site' failed; use -v for traceback
Could not find platform independent libraries <prefix>
Could not find platform dependent libraries <exec_prefix>
Consider setting $PYTHONHOME to <prefix>[:<exec_prefix>]
'import site' failed; use -v for traceback
Could not find platform independent libraries <prefix>
Could not find platform dependent libraries <exec_prefix>
Consider setting $PYTHONHOME to <prefix>[:<exec_prefix>]
'import site' failed; use -v for traceback
Could not find platform independent libraries <prefix>
Could not find platform dependent libraries <exec_prefix>
Consider setting $PYTHONHOME to <prefix>[:<exec_prefix>]
'import site' failed; use -v for traceback
[Wed Sep 30 12:13:05 2015] [notice] caught SIGTERM, shutting down
[Wed Sep 30 12:14:11 2015] [notice] suEXEC mechanism enabled (wrapper: /usr/sbin/suexec)
[Wed Sep 30 12:14:11 2015] [notice] Digest: generating secret for digest authentication ...
[Wed Sep 30 12:14:11 2015] [notice] Digest: done
[Wed Sep 30 12:14:13 2015] [error] avahi_client_new() failed: Access denied
[Wed Sep 30 12:14:13 2015] [notice] Apache/2.2.15 (Unix) DAV/2 PHP/5.5.29 mod_ssl/2.2.15 OpenSSL/1.0.1e-fips mod_wsgi/3.2 Python/2.6.6 configured -- resuming normal operations
[Wed Sep 30 12:40:58 2015] [error] [client 192.168.50.52] (13)Permission denied: access to /test.php denied
[Wed Sep 30 12:41:06 2015] [error] [client 192.168.50.52] (13)Permission denied: access to /tools denied
[Wed Sep 30 12:42:09 2015] [error] [client 192.168.50.52] (13)Permission denied: access to / denied


/var/lib/mysql/myhost.err [ error code 13: permission denied ]
150930 13:07:16 mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql
150930 13:07:16 [Note] /usr/libexec/mysqld (mysqld 5.5.45-log) starting as process 4481 ...
150930 13:07:16 [Note] Plugin 'FEDERATED' is disabled.
/usr/libexec/mysqld: Table 'plugin' is read only
150930 13:07:16 [ERROR] Can't open the mysql.plugin table. Please run mysql_upgrade to create it.
150930 13:07:16 InnoDB: The InnoDB memory heap is disabled
150930 13:07:16 InnoDB: Mutexes and rw_locks use GCC atomic builtins
150930 13:07:16 InnoDB: Compressed tables use zlib 1.2.3
150930 13:07:16 InnoDB: Using Linux native AIO
/usr/libexec/mysqld: Can't create/write to file '/tmp/ibnujgie' (Errcode: 13)
150930 13:07:16 InnoDB: Error: unable to create temporary file; errno: 13
150930 13:07:16 [ERROR] Plugin 'InnoDB' init function returned error.
150930 13:07:16 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
150930 13:07:16 [ERROR] Unknown/unsupported storage engine: InnoDB
150930 13:07:16 [ERROR] Aborting

150930 13:07:16 [Note] /usr/libexec/mysqld: Shutdown complete

150930 13:07:16 mysqld_safe mysqld from pid file /var/run/mysqld/mysqld.pid ended



ssh login screeen:
Last login: Wed Sep 30 10:30:30 2015 from a00000638050820.mydomain.com
Could not chdir to home directory /home/neilm: Permission denied
/bin/bash: Permission denied



root@mydomain ~]# ls -l /
total 237
dr-xr-xr-x. 2 root root 4096 Sep 12 03:26 bin
dr-xr-xr-x. 5 root root 4096 Aug 20 14:06 boot
drwxr-xr-x. 2 root root 4096 Jul 24 04:08 cgroup
drwxr-xr-x 18 root root 3720 Sep 30 12:14 dev
drwxr-xr-x. 126 root root 12288 Sep 30 12:14 etc
drwxr-xr-x. 15 root root 4096 Sep 22 16:17 home
dr-xr-xr-x. 11 root root 4096 Aug 20 14:01 lib
dr-xr-xr-x. 10 root root 12288 Sep 12 03:26 lib64
drwx------. 2 root root 16384 Apr 9 2013 lost+found
drwxr-xr-x. 2 root root 4096 Apr 29 2013 media
drwxr-xr-x 2 root root 0 Sep 30 12:14 misc
drwxr-xr-x. 4 root root 4096 Dec 18 2013 mnt
drwxr-xr-x 2 root root 0 Sep 30 12:14 net
drwxr-xr-x. 6 root root 4096 May 18 11:33 opt
-rw-r--r--. 1 root root 0 Dec 10 2013 perllocal.pod
dr-xr-xr-x 155 root root 0 Sep 30 12:13 proc
dr-xr-x---. 33 root root 4096 Sep 29 09:45 root
dr-xr-xr-x. 2 root root 12288 Sep 12 03:26 sbin
drwxr-xr-x. 2 root root 4096 Apr 9 2013 selinux
drwxr-xr-x. 2 root root 4096 Sep 23 2011 srv
drwxr-xr-x 13 root root 0 Sep 30 12:13 sys
drwxrwxrwt. 21 root root 131072 Sep 30 12:14 tmp
drwxr-xr-x. 13 root root 4096 Apr 9 2013 usr
drwxr-xr-x. 24 root root 4096 May 8 2014 var

root@mydomain# ls -l /home
total 52
drwxrwxr-x. 31 neilm neilm 4096 Sep 23 14:53 neilm


Any ideas where to start looking ?

Thanks, Neil M

[aks]

mysql inserts completing ok but not actually being added to table
Okay, that's a really bad thing (TM). But I have to ask, how do you know that the change(s) have not been flushed to disk?

fatal: open lock file /var/lib/postfix/master.lock: cannot open file: Permission denied
Check permission in the file, the directory and all directories going back to the root.
Running this might help troubleshoot:
sudo -u postfix /bin/bash
touch /var/lib/postfix/master.lock
Perhaps just reinstall postfix?

You also seem to have many, many permission denied (and you have SELinux disabled which is a bad thing). Are you sure you've not been compromised (the Xor malware springs to mind - <sarcasm>thank you so much media companies</sarcasm>)

Wow, that was a long post.

[NeilMatch]

Thanks for the reply,
I don't believe is a malware issue as this server is not directly connected to the internet. All installs are done via 'yum' or installed from source code.

I tried your suggestion and the results are below:

root@mydomain ~]# sudo -u postfix /bin/bash
sudo: unable to stat /etc/sudoers: Permission denied
sudo: no valid sudoers sources found, quitting
sudo: unable to initialize policy plugin

(on bad server)
[root@mydomain ~]# ls -l / | grep etc
drwxr-xr-x. 126 root root 12288 Oct 1 03:42 etc

root@mydomain ~]# ls -l /etc/sudoers
-r--r-----. 1 root root 4046 Jun 18 13:43 /etc/sudoers


(on good server)
[root@mydomain ~]# ls -l / | grep etc
drwxr-xr-x. 123 root root 12288 Oct 1 03:48 etc

root@netflow-collector-vm-n01 ~]# ls -l /etc/sudoers
-r--r-----. 1 root root 4002 Mar 2 2012 /etc/sudoers


As you can see, the problem is not postfix specific so I don't think reinstalling postfix will fix everything (assuming I currently have permission to do the install).

I can't get pass the thought that I was playing with '/etc/sudoers.d' when all of this started happening but I can't see anything wrong.
It almost looks like the 'root' user has lost some of its permissions/authorisation ??

NeilM

[NeilMatch]

Found this in: /var/log/secure
Sep 28 16:25:48 edn-web-vm-n01 sudo: root : TTY=pts/1 ; PWD=/home/vulnerabilities/Maildir ; USER=root ; COMMAND=/usr/local/bin/sqlProcmail
Sep 28 16:25:48 edn-web-vm-n01 sudo: root : TTY=pts/1 ; PWD=/home/vulnerabilities/Maildir ; USER=root ; COMMAND=/bin/chmod 666 /

and this in /var/log/messages:
Sep 28 16:25:48 mydomain Error: /usr/local/bin/sqlProcmail - Started without any input arguments.... exiting
Sep 28 16:25:48 mydomain Error: /usr/local/bin/sqlProcmail - mySQL INSERT Error: 1048, Column 'subject' cannot be null
Sep 28 16:25:48 mydomain Error: /usr/local/bin/sqlProcmail - Vendor: , Subject: , Filename: /
Sep 28 16:26:34 mydomain ntpd[2584]: Deleting interface #7 eth2, fe80::20c:29ff:fe74:ff02#123, interface stats: received=0, sent=0, dropped=0, active_time=608425 secs
Sep 28 16:26:34 mydomain ntpd[2584]: Deleting interface #6 lo, ::1#123, interface stats: received=0, sent=0, dropped=0, active_time=608425 secs
Sep 28 16:26:34 mydomain ntpd[2584]: Deleting interface #5 eth1, fe80::20c:29ff:fe74:fff8#123, interface stats: received=0, sent=0, dropped=0, active_time=608425 secs
Sep 28 16:32:31 mydomain kernel: type=1400 audit(1443421951.013:95): avc: denied { dac_override } for pid=3223 comm="nmbd" capability=1 scontext=system_u:system_r:nmbd_t:s0 tcontext=system_u:system_r:nmbd_t:s0 tclass=capability
Sep 28 16:40:46 mydomain kernel: type=1400 audit(1443422446.723:96): avc: denied { dac_override } for pid=3223 comm="nmbd" capability=1 scontext=system_u:system_r:nmbd_t:s0 tcontext=system_u:system_r:nmbd_t:s0 tclass=capability
Sep 28 16:55:46 mydomain kernel: type=1400 audit(1443423346.745:97): avc: denied { dac_override } for pid=3223 comm="nmbd" capability=1 scontext=system_u:system_r:nmbd_t:s0 tcontext=system_u:system_r:nmbd_t:s0 tclass=capability

This was me testing a script; the command was meant to be: /bin/chmod 666 /Alerts/new/1443417902.14991_0.mydomian
As you can see, I did have selinux running (in permissive mode) at the time. I disabled it later in case it was causing the problem.

The '/' directory looks ok but this is about when my problems started. I'm 99.8% certian this this propblem is self inflicted but I see where the damage has been done!
There isn't a file called "/" is there ?

NeilM

[gerald_clark]

[root@h2 ~]# ls -ld /
dr-xr-xr-x. 25 root root 4096 Sep 30 07:31 /
[root@h2 ~]#

[NeilMatch]

Bingo!!!!

[root@mydomain ~]# ls -ld /
drw-rw-rw-. 27 root root 4096 Sep 30 12:13 /

I've issued a 'chmod 555 /' and restarted the server.... all good.

I'm not sure why the 'find / -perm 666' didn't show this up but then thinking about it, it would only work on everything within the / directory, not the / directory itself.... which is exactly what I did as well....

Many thanks for your help.

NeilM