Problem Note 56230: SAS® Metadata Server under Linux is unresponsive when you run a metadata backup (with Reorganize option set) after the December 31, 2016 leap second
 |  |  |  |
On December 31, 2016, the International Earth Rotation and Reference Systems Service added a leap second to Coordinated Universal Time (UTC) in order to bring it closer to mean solar time (UT1). Prior to December, a leap second was most recently added on June 30, 2015. The issues described here were first seen after the 2015 leap second.
Problem
In some Linux operating environments, this additional leap second results in the metadata server becoming unresponsive after the first metadata backup, with the Reorganize option set, runs after December 31.
The default metadata backup schedule, with the Reorganize option set in order to reorganize the repositories, is configured to run on Mondays at 1:00 AM, as shown below:
This schedule means that for most sites that experienced this issue, the problem would have occurred on January 2, 2017 at around 1:00 AM, and then possibly every Monday thereafter.
The examples listed below show some of the ways the problem manifests in the metadata log file:
SAS® 9.3 TS1M2
2015-07-13T00:59:59,935 INFO [00119967] :sas - The Backup is performing a REORG of the repository data sets to remove dead space.
2015-07-13T00:59:59,993 WARN [00119967] :sas - MVA task is still busy after 200 wait periods. Request denied.
2015-07-13T00:59:59,993 INFO [00119967] :sas - MVA task is still busy after 200 wait periods. Request denied.
2015-07-13T00:59:59,993 WARN [00119967] :sas - Due to a large number of pending updates, your request cannot be performed at this time. Please try again later.
2015-07-13T01:00:00,014 WARN [00119967] :sas - MVA task is still busy after 200 wait periods. Request denied.
2015-07-13T01:00:00,034 WARN [00119967] :sas - MVA task is still busy after 200 wait periods. Request denied.
2015-07-13T01:00:00,054 WARN [00119967] :sas - MVA task is still busy after 200 wait periods. Request denied.
2015-07-13T00:59:59,993 WARN [00119967] :sas - MVA task is still busy after 200 wait periods. Request denied.
2015-07-13T00:59:59,993 INFO [00119967] :sas - MVA task is still busy after 200 wait periods. Request denied.
2015-07-13T00:59:59,993 WARN [00119967] :sas - Due to a large number of pending updates, your request cannot be performed at this time. Please try again later.
2015-07-13T01:00:00,014 WARN [00119967] :sas - MVA task is still busy after 200 wait periods. Request denied.
2015-07-13T01:00:00,034 WARN [00119967] :sas - MVA task is still busy after 200 wait periods. Request denied.
2015-07-13T01:00:00,054 WARN [00119967] :sas - MVA task is still busy after 200 wait periods. Request denied.
2015-07-13T01:00:53,653 ERROR [00119966] 5:sasadm@saspw - The SAS Metadata Server I/O subsystem has returned error message ' ERROR: Write access to member TMP000.PERSON.DATA is denied.'. Contact the SAS Metadata Server administrator for assistance.
2015-07-13T01:00:53,653 INFO [00119966] 5:sasadm@saspw - mOMScookiejarGetCookie rc=807feb13....
2015-07-13T01:00:53,653 ERROR [00119966] 5:sasadm@saspw - The A0000001 container cannot be opened in update mode in the REPOSMGR repository.
2015-07-13T01:00:53,653 INFO [00119966] 5:sasadm@saspw - mOMScookiejarGetCookie rc=807feb13....
2015-07-13T01:00:53,653 ERROR [00119966] 5:sasadm@saspw - The A0000001 container cannot be opened in update mode in the REPOSMGR repository.
...The last three messages occur on each attempted client login until the server is restarted...
SAS® 9.3 TS1M2
2015-07-20T01:00:13,625 INFO [02965951] :sas - The Backup is performing a REORG of the repository data sets to remove dead space.
2015-07-20T01:00:13,884 INFO [02965951] :sas - MVA task is still busy after 200 wait periods. Request denied.
2015-07-20T01:00:13,884 WARN [02965951] :sas - Due to a large number of pending updates, your request cannot be performed at this time. Please try again later.
2015-07-20T01:00:13,904 WARN [02965951] :sas - MVA task is still busy after 200 wait periods. Request denied.
2015-07-20T01:00:13,925 WARN [02965951] :sas - MVA task is still busy after 200 wait periods. Request denied.
2015-07-20T01:00:13,952 WARN [02965951] :sas - MVA task is still busy after 200 wait periods. Request denied.
2015-07-20T01:00:13,953 INFO [02965951] :sas - Journal Reload complete. 0 entries with entry numbers from 0 to 0.
2015-07-20T01:00:13,953 INFO [02965951] :sas - The Backup has completed successfully.
2015-07-20T01:00:26,742 ERROR [02965967] 9:sastrust@saspw - The SAS Metadata Server I/O subsystem has returned error message ' ERROR: Write access to member TMP000.TREE.DATA is denied.'. Contact the SAS Metadata Server administrator for assistance.
2015-07-20T01:00:26,742 INFO [02965967] 9:sastrust@saspw - The tree container cannot be opened in update mode in the Foundation repository.
2015-07-20T01:00:26,742 INFO [02965967] 9:sastrust@saspw - GetMetadataObjects return code=807feb13....
2015-07-20T01:00:26,742 ERROR [02965967] 9:sastrust@saspw - The tree container cannot be opened in update mode in the Foundation repository.
2015-07-20T01:00:28,514 ERROR [02966068] 9:sastrust@saspw - The SAS Metadata Server I/O subsystem has returned error message ' ERROR: Write access to member TMP000.DEPCOMP.DATA is denied.'. Contact the SAS Metadata Server administrator for assistance.
2015-07-20T01:00:35,556 ERROR [02966070] 1744:sasadm@saspw - The SAS Metadata Server I/O subsystem has returned error message ' ERROR: Write access to member TMP000.TREE.DATA is denied.'. Contact the SAS Metadata Server administrator for assistance.
2015-07-20T01:00:35,556 INFO [02966070] 1744:sasadm@saspw - GetMetadata return code=807feb13....
2015-07-20T01:00:35,556 ERROR [02966070] 1744:sasadm@saspw - The tree container cannot be opened in update mode in the Foundation repository.
2015-07-20T01:00:35,916 ERROR [02966072] :sas - The SAS Metadata Server I/O subsystem has returned error message 'Invalid open mode for file.'. Contact the SAS Metadata Server administrator for assistance.
2015-07-20T01:00:35,917 ERROR [02966072] :sas - Partial workunit commit. container=1 A6GMREPO.itrnlgi queue=2 UPDATE queue item=0.
2015-07-20T01:00:35,917 ERROR [02966072] :sas - The error which caused the commit to fail is: 807fea8a
2015-07-20T01:00:35,917 ERROR [02966072] :sas - The SAS Metadata Server I/O subsystem has returned error message 'Invalid open mode for file.'. Contact the SAS Metadata Server administrator for assistance.
2015-07-20T01:00:35,917 ERROR [02966072] :sas - Emergency situation requires we discard all in memory data which may have been affected.
2015-07-20T01:00:35,917 ERROR [02966072] :sas - *** FOMSworkunitCommit: Close and unload container #1 A6GMREPO.itrnlgi ***
2015-07-20T01:00:39,562 ERROR [02966073] 1744:sasadm@saspw - The SAS Metadata Server I/O subsystem has returned error message ' ERROR: Write access to member TMP000.TREE.DATA is denied.'. Contact the SAS Metadata Server administrator for assistance.
2015-07-20T01:00:39,562 INFO [02966073] 1744:sasadm@saspw - GetMetadata return code=807feb13....
2015-07-20T01:00:39,562 ERROR [02966073] 1744:sasadm@saspw - The tree container cannot be opened in update mode in the Foundation repository.
2015-07-20T01:00:13,884 INFO [02965951] :sas - MVA task is still busy after 200 wait periods. Request denied.
2015-07-20T01:00:13,884 WARN [02965951] :sas - Due to a large number of pending updates, your request cannot be performed at this time. Please try again later.
2015-07-20T01:00:13,904 WARN [02965951] :sas - MVA task is still busy after 200 wait periods. Request denied.
2015-07-20T01:00:13,925 WARN [02965951] :sas - MVA task is still busy after 200 wait periods. Request denied.
2015-07-20T01:00:13,952 WARN [02965951] :sas - MVA task is still busy after 200 wait periods. Request denied.
2015-07-20T01:00:13,953 INFO [02965951] :sas - Journal Reload complete. 0 entries with entry numbers from 0 to 0.
2015-07-20T01:00:13,953 INFO [02965951] :sas - The Backup has completed successfully.
2015-07-20T01:00:26,742 ERROR [02965967] 9:sastrust@saspw - The SAS Metadata Server I/O subsystem has returned error message ' ERROR: Write access to member TMP000.TREE.DATA is denied.'. Contact the SAS Metadata Server administrator for assistance.
2015-07-20T01:00:26,742 INFO [02965967] 9:sastrust@saspw - The tree container cannot be opened in update mode in the Foundation repository.
2015-07-20T01:00:26,742 INFO [02965967] 9:sastrust@saspw - GetMetadataObjects return code=807feb13....
2015-07-20T01:00:26,742 ERROR [02965967] 9:sastrust@saspw - The tree container cannot be opened in update mode in the Foundation repository.
2015-07-20T01:00:28,514 ERROR [02966068] 9:sastrust@saspw - The SAS Metadata Server I/O subsystem has returned error message ' ERROR: Write access to member TMP000.DEPCOMP.DATA is denied.'. Contact the SAS Metadata Server administrator for assistance.
2015-07-20T01:00:35,556 ERROR [02966070] 1744:sasadm@saspw - The SAS Metadata Server I/O subsystem has returned error message ' ERROR: Write access to member TMP000.TREE.DATA is denied.'. Contact the SAS Metadata Server administrator for assistance.
2015-07-20T01:00:35,556 INFO [02966070] 1744:sasadm@saspw - GetMetadata return code=807feb13....
2015-07-20T01:00:35,556 ERROR [02966070] 1744:sasadm@saspw - The tree container cannot be opened in update mode in the Foundation repository.
2015-07-20T01:00:35,916 ERROR [02966072] :sas - The SAS Metadata Server I/O subsystem has returned error message 'Invalid open mode for file.'. Contact the SAS Metadata Server administrator for assistance.
2015-07-20T01:00:35,917 ERROR [02966072] :sas - Partial workunit commit. container=1 A6GMREPO.itrnlgi queue=2 UPDATE queue item=0.
2015-07-20T01:00:35,917 ERROR [02966072] :sas - The error which caused the commit to fail is: 807fea8a
2015-07-20T01:00:35,917 ERROR [02966072] :sas - The SAS Metadata Server I/O subsystem has returned error message 'Invalid open mode for file.'. Contact the SAS Metadata Server administrator for assistance.
2015-07-20T01:00:35,917 ERROR [02966072] :sas - Emergency situation requires we discard all in memory data which may have been affected.
2015-07-20T01:00:35,917 ERROR [02966072] :sas - *** FOMSworkunitCommit: Close and unload container #1 A6GMREPO.itrnlgi ***
2015-07-20T01:00:39,562 ERROR [02966073] 1744:sasadm@saspw - The SAS Metadata Server I/O subsystem has returned error message ' ERROR: Write access to member TMP000.TREE.DATA is denied.'. Contact the SAS Metadata Server administrator for assistance.
2015-07-20T01:00:39,562 INFO [02966073] 1744:sasadm@saspw - GetMetadata return code=807feb13....
2015-07-20T01:00:39,562 ERROR [02966073] 1744:sasadm@saspw - The tree container cannot be opened in update mode in the Foundation repository.
SAS® 9.4 TS1M2
2015-07-13T00:59:59,621 INFO [00408086] :sas - The Backup is performing a REORG of the repository data sets to remove dead space.
2015-07-13T00:59:59,632 WARN [00408086] :sas - MVA task is still busy after 200 wait periods. Request denied.
2015-07-13T00:59:59,632 INFO [00408086] :sas - MVA task is still busy after 200 wait periods. Request denied.
2015-07-13T00:59:59,632 WARN [00408086] :sas - Due to a large number of pending updates, your request cannot be performed at this time. Please try again later.
2015-07-13T00:59:59,644 WARN [00408086] :sas - MVA task is still busy after 200 wait periods. Request denied.
2015-07-13T00:59:59,644 INFO [00408086] :sas - MVA task is still busy after 200 wait periods. Request denied.
2015-07-13T00:59:59,655 WARN [00408086] :sas - MVA task is still busy after 200 wait periods. Request denied.
2015-07-13T00:59:59,655 INFO [00408086] :sas - MVA task is still busy after 200 wait periods. Request denied.
2015-07-13T00:59:59,739 WARN [00408086] :sas - The file was not found: mdassoc.
2015-07-13T00:59:59,753 ERROR [00408086] :sas - The file is already locked by another user.
2015-07-13T00:59:59,756 INFO [00408086] :sas - Journal Reload complete. 0 entries with entry numbers from 0 to 0.
2015-07-13T00:59:59,757 INFO [00408086] :sas - The Backup has completed unsuccessfully.
2015-07-13T01:00:00,004 ERROR [00408085] 17309:sasevs@saspw - The SAS Metadata Server I/O subsystem has returned error message ' ERROR: Write access to member RPOSMGR.RPOSCTRL.DATA is denied.'. Contact the SAS Metadata Server administrator for assistance.
2015-07-13T01:00:00,005 INFO [00408085] 17309:sasevs@saspw - GetMetadataObjects return code=807feb13....
2015-07-13T01:00:00,005 ERROR [00408085] 17309:sasevs@saspw - The rposctrl container cannot be opened in update mode in the REPOSMGR repository.
2015-07-13T10:35:03,011 ERROR [00428526] 24100:sasdemo - The SAS Metadata Server I/O subsystem has returned error message ' ERROR: Write access to member TMP000.LOGIN.DATA is denied.'. Contact the SAS Metadata Server administrator for assistance.
2015-07-13T10:35:03,012 INFO [00428526] 24100:sasdemo - mOMScookiejarGetCookie rc=807feb13....
2015-07-13T10:35:03,012 ERROR [00428526] 24100:sasdemo - The A0000001 container cannot be opened in update mode in the REPOSMGR repository.
2015-07-13T00:59:59,632 WARN [00408086] :sas - MVA task is still busy after 200 wait periods. Request denied.
2015-07-13T00:59:59,632 INFO [00408086] :sas - MVA task is still busy after 200 wait periods. Request denied.
2015-07-13T00:59:59,632 WARN [00408086] :sas - Due to a large number of pending updates, your request cannot be performed at this time. Please try again later.
2015-07-13T00:59:59,644 WARN [00408086] :sas - MVA task is still busy after 200 wait periods. Request denied.
2015-07-13T00:59:59,644 INFO [00408086] :sas - MVA task is still busy after 200 wait periods. Request denied.
2015-07-13T00:59:59,655 WARN [00408086] :sas - MVA task is still busy after 200 wait periods. Request denied.
2015-07-13T00:59:59,655 INFO [00408086] :sas - MVA task is still busy after 200 wait periods. Request denied.
2015-07-13T00:59:59,739 WARN [00408086] :sas - The file was not found: mdassoc.
2015-07-13T00:59:59,753 ERROR [00408086] :sas - The file is already locked by another user.
2015-07-13T00:59:59,756 INFO [00408086] :sas - Journal Reload complete. 0 entries with entry numbers from 0 to 0.
2015-07-13T00:59:59,757 INFO [00408086] :sas - The Backup has completed unsuccessfully.
2015-07-13T01:00:00,004 ERROR [00408085] 17309:sasevs@saspw - The SAS Metadata Server I/O subsystem has returned error message ' ERROR: Write access to member RPOSMGR.RPOSCTRL.DATA is denied.'. Contact the SAS Metadata Server administrator for assistance.
2015-07-13T01:00:00,005 INFO [00408085] 17309:sasevs@saspw - GetMetadataObjects return code=807feb13....
2015-07-13T01:00:00,005 ERROR [00408085] 17309:sasevs@saspw - The rposctrl container cannot be opened in update mode in the REPOSMGR repository.
2015-07-13T10:35:03,011 ERROR [00428526] 24100:sasdemo - The SAS Metadata Server I/O subsystem has returned error message ' ERROR: Write access to member TMP000.LOGIN.DATA is denied.'. Contact the SAS Metadata Server administrator for assistance.
2015-07-13T10:35:03,012 INFO [00428526] 24100:sasdemo - mOMScookiejarGetCookie rc=807feb13....
2015-07-13T10:35:03,012 ERROR [00428526] 24100:sasdemo - The A0000001 container cannot be opened in update mode in the REPOSMGR repository.
...The last three messages occur on each attempted client login until the server is restarted...
Solutions
The short-term solution to the issue is to stop and restart the metadata server.
The long-term solution is to reboot the Linux operating system. If you cannot reboot the Linux machine before the next scheduled backup that has the Reorganize option set, then you can disable the Reorganize option temporarily. For details, see the appropriate document below for your release of the SAS® System:
- SAS 9.3 Metadata Server Backup Tasks (in SAS® 9.3 Intelligence Platform: System Administration Guide, Second Edition)
- SAS 9.4 Metadata Server Backup Tasks (in SAS® 9.4 Intelligence Platform: System Administration Guide, Fourth Edition)
Operating System and Release Information
| Product Family | Product | System | Product Release | SAS Release | ||
| Reported | Fixed* | Reported | Fixed* | |||
| SAS System | SAS Metadata Server | Linux | 9.3 | |||
| Linux for x64 | 9.3 | |||||
By default, a metadata backup that has the Reorganize option set runs on Mondays at 1:00 AM local time. After the addition of a leap second on December 31, 2016, running the backup with this option results in the Foundation repository going offline, preventing clients from connecting.
| Type: | Problem Note |
| Priority: | high |
| Date Modified: | 2015-07-30 14:18:46 |
| Date Created: | 2015-07-21 13:48:56 |