Autosys Jobs failing with exitcode 4030 "Invalid command: not listed in oscomponent.validcommand"
Article ID: 256445
Updated On:
Products
Issue/Introduction
Post upgrading the autosys agents to r12.0. The jobs sporadically failing with the following error:
#autorep -J test-job
Job Name Last Start Last End ST/Ex Run/Ntry Pri/Xit
________________________________________________________________ ____________________ ____________________ _____ ________ _______
test-job 12/12/2022 14:47:06 12/12/2022 14:47:16 SU 32528/1 0
Status/[Event] Time Ntry ES ProcessTime Machine
-------------- --------------------- -- -- --------------------- ----------------------------------------
STARTING 12/12/2022 03:06:00 1 PD 12/12/2022 03:06:00 agent-machine
RUNNING 12/12/2022 03:06:00 1 PD 12/12/2022 03:06:01 agent-machine
<Automatically generated this event to stand in for one omitted by the agent.>
FAILURE 12/12/2022 03:09:00 1 PD 12/12/2022 03:09:01
<Invalid command: not listed in oscomponent.validcommand>
[*** ALARM ***]
JOBFAILURE 12/12/2022 03:09:02 1 PD 12/12/2022 03:09:02 agent-machine
[FORCE_STARTJOB] 12/12/2022 14:47:06 0 PD 12/12/2022 14:47:06
STARTING 12/12/2022 14:47:06 2 PD 12/12/2022 14:47:06 agent-machine
RUNNING 12/12/2022 14:47:06 2 PD 12/12/2022 14:47:07 agent-machine
<Executing at WA_AGENT>
SUCCESS 12/12/2022 14:47:16 2 PD 12/12/2022 14:47:16 agent-machine
[STARTJOB] 12/13/2022 03:10:00 0 UP
<Event was scheduled based on job definition.>
The Runner OS log of the agent logs (<AGENT_INSTALL_DIR/logs/runner_os_component.log) has the following message captured -
12/14/2022 03:06:11.183+0900: Job .32527_1/WAAE_WF0.1/MAIN has finished with exit code 0
12/14/2022 03:06:11.183+0900: Transmitter: Sending AFM: 20221214 03061100-0900 JavaAgent#tcpip@ACE_SCH OS_COMPONENT 610.32527_1/WAAE_WF0.1/MAIN State COMPLETE Cmpc(0) SetEnd
12/14/2022 03:06:11.183+0900: Map: Garbage collection starts
12/14/2022 03:06:11.183+0900: Map: Garbage collection completed
12/14/2022 03:08:28.423+0900: Warning: Disk resource threshold of 31457280 breached, current disk space is 30756864. Sending notice
12/14/2022 03:08:28.423+0900: invoking CybAgentDriver.setDiskResourceMode(1, "Disk resource below threshold.")
12/14/2022 03:08:31.424+0900: Severe Warning: Disk resource threshold of 20971520 breached, current disk space is 16920576.
12/14/2022 03:08:31.424+0900: invoking CybAgentDriver.setDiskResourceMode(2, "Disk resource below severe threshold.")
12/14/2022 03:08:33.425+0900: Critical: Disk resource threshold of 10485760 breached, current disk space is 6303744. Agent is entering persist to memory mode.
12/14/2022 03:08:33.425+0900: invoking CybAgentDriver.setDiskResourceMode(4, "Disk resource below critical threshold. Agent is entering persist to memory mode.")
12/14/2022 03:08:33.426+0900: Persistence disabled, keeping caches in memory
12/14/2022 03:08:33.426+0900: Runner: persistence switched to in memory
12/14/2022 03:08:33.426+0900: Map: persistence switched to in memory.
12/14/2022 03:08:33.426+0900: Queue: persistence switched to in memory.
12/14/2022 03:09:00.179+0900: Preparing job 610.32528_1/WAAE_WF0.1/MAIN - 20221214 03090017-0900 WA_AGENT JavaAgent#tcpip@ACE_SCH 610.32528_1/WAAE_WF0.1/MAIN RUN . Data(Args="/job/args/test-job",Command="/autosys/jobs/test.sh") Env(AUTOSERV=ACE,AUTO_JOB_NAME="test-job",AUTORUN="32528-1") User(...) Password(...) MFUser(...) WOBRequestID(8E935B593F791188D2370A1F719CC3E5F888B30516709549401780) GblEnv(AUTOSYS="/SW/CA/WorkloadAutomationAE/autosys",AUTOROOT="/SW/CA/WorkloadAutomationAE",EWAGLOBALPROFILE="/etc/auto.profile") JLErase(TRUE) SpoolErase(TRUE)
12/14/2022 03:09:00.181+0900: Job 610.32528_1/WAAE_WF0.1/MAIN starting
12/14/2022 03:09:00.190+0900: Job 610.32528_1/WAAE_WF0.1/MAIN has finished with exit code 0
12/14/2022 03:09:00.190+0900: Transmitter: Sending AFM: 20221214 03090000-0900 JavaAgent#tcpip@ACE_SCH OS_COMPONENT 610.32528_1/WAAE_WF0.1/MAIN State SUBERROR Failed SetEnd Status(Invalid command: not listed in oscomponent.validcommand) Cmpc(4030)
12/14/2022 03:10:00.441+0900: Preparing job 489.32531_1/WAAE_WF0.1/MAIN - 20221214 03100037-0900 WA_AGENT JavaAgent#tcpip@ACE_SCH 489.32531_1/WAAE_WF0.1/MAIN RUN . Data(Args="kr/or/geps/scb/sg/sg/cfg/ScbSgSgRxcpCfcGdc_CFG",Command="/autosys/jobs/test.sh") ComponentType(AUTOSYS.APPSRV) Attribute1(Type=AsServers,Value=autosys-servder) Attribute2(Type=AsPort,Value=9000) Attribute3(Type=AsToken,Value=0X41F31FDBFAFF6BF3A12771A8E2E56938A1DB116C9DBC3F67BBA076A15E078F99305D71081926DDC71F7AC8139877C60BD8649942CB01) Env(AUTOSERV=ACE,AUTO_JOB_NAME="test-job",AUTORUN="32531-1",STDERR=>>"/SW/CA/$AUTO_JOB_NAME.$AUTORUN.`date +%Y%m%d`.err") User(...) Password(...) MFUser(...) WOBRequestID(8E935B593F791188D2370A1F719CC3E5F888B30516709550004360) GblEnv(AUTOSYS="/SW/CA/WorkloadAutomationAE/autosys",AUTOROOT="/SW/CA/WorkloadAutomationAE",EWAGLOBALPROFILE="/etc/auto.profile") JLErase(TRUE) SpoolErase(TRUE)
12/14/2022 03:10:00.442+0900: Job 489.32531_1/WAAE_WF0.1/MAIN starting
12/14/2022 03:10:00.451+0900: Preparing job 518.32391_1/WAAE_WF0.1/MAIN - 20221214 03100038-0900 WA_AGENT JavaAgent#tcpip@ACE_SCH 518.32391_1/WAAE_WF0.1/MAIN RUN . Data(Args="kr/or/geps/scb/ic/ic/cfg/ScbIcIcHiraChckTrn_CFG",Command="/autosys/jobs/test.sh") ComponentType(AUTOSYS.APPSRV) Attribute1(Type=AsServers,Value=autosys-servder) Attribute2(Type=AsPort,Value=9000) Attribute3(Type=AsToken,Value=0X41F31FDBFAFF318AF233ED2B2994F3D47F1CCF7EB27C2916438E3B814CFE75734761069DE126B5C59D33A17540F2D69C3829CFB13269) Env(AUTOSERV=ACE,AUTO_JOB_NAME="test-job-01",AUTORUN="32391-1",STDERR=>>"/logs/autosys/log/scb/$AUTO_JOB_NAME.$AUTORUN.`date +%Y%m%d`.err") User(...) Password(...) MFUser(...) WOBRequestID(8E935B593F791188D2370A1F719CC3E5F888B30516709550004440) GblEnv(AUTOSYS="/SW/CA/WorkloadAutomationAE/autosys",AUTOROOT="/SW/CA/WorkloadAutomationAE",EWAGLOBALPROFILE="/etc/auto.profile") JLErase(TRUE) SpoolErase(TRUE)
12/14/2022 03:10:00.452+0900: Job 518.32391_1/WAAE_WF0.1/MAIN starting
12/14/2022 03:10:00.453+0900: Job 489.32531_1/WAAE_WF0.1/MAIN has finished with exit code 0
12/14/2022 03:10:00.453+0900: Transmitter: Sending AFM: 20221214 03100000-0900 JavaAgent#tcpip@ACE_SCH OS_COMPONENT 489.32531_1/WAAE_WF0.1/MAIN State SUBERROR Failed SetEnd Status(Invalid command: not listed in oscomponent.validcommand) Cmpc(4030)
Environment
Component: Autosys System Agent
Release : 12.0, 12.1
Cause
Server ran out of disk space. The available space on the disk is less than the the critical threshold set in the agentparm.txt -
agent.resourcemon.threshold.disk.warning.notice=30M
agent.resourcemon.threshold.disk.warning.severe=20M
agent.resourcemon.threshold.disk.critical=10M
When the disk space is lower than the critical threshold, the agent would stop writing/using the agent database directory. Instead, it will persist in memory and continue to execute the jobs.
The jobs would fail with the said error "SetEnd Status(Invalid command: not listed in oscomponent.validcommand) Cmpc(4030)" if the agent is unable to create/execute the temporary wrapper scripts to trigger the job.
Resolution
No action needed from the autosys or agent side. The application teams need to contact the system administrator to resolve the disk space issue where the agent is installed on the server.
Increase the alert limits to higher so the application teams will have enough time to address the disk space issue while the jobs continue to run (persist in memory).
agent.resourcemon.threshold.disk.warning.notice=30M
agent.resourcemon.threshold.disk.warning.severe=20M
agent.resourcemon.threshold.disk.critical=10M
The agent would switch persistence to database (disk) as soon as the space is available. It will start processing the newly submitted jobs right after there is enough disk space available.
The runner_os_component.log of the agent install directory would log the following messages -
12/14/2012/14/2022 04:53:50.910+0900: Transmitter: Sending AFM: 20221214 04535000-0900 JavaAgent#tcpip@ACE_SCH OS_COMPONENT 589.32394_1/WAAE_WF0.1/MAIN State COMPLETE Cmpc(0) SetEnd
12/14/2022 04:53:52.084+0900: Job 589.32394_1/WAAE_WF0.1/MAIN has finished with exit code 0
12/14/2022 04:53:52.908+0900: Info: Disk resource no longer breaching any thresholds, current disk space is 14895026176.
12/14/2022 04:53:52.908+0900: Agent will no longer be in persist to memory mode.
12/14/2022 04:53:52.908+0900: invoking CybAgentDriver.setDiskResourceMode(0, "Condition cleared")
12/14/2022 04:53:52.914+0900: Persistence enabled, writing caches to database
12/14/2022 04:53:52.914+0900: Runner: persistence switched to disk
12/14/2022 04:53:52.914+0900: Map: persistence switched to disk.
12/14/2022 04:53:52.914+0900: Map: started flushing the cache to disk.
12/14/2022 04:53:52.914+0900: Map: Garbage collection starts
12/14/2022 04:53:52.914+0900: Map: Garbage collection completed
12/14/2022 04:53:52.915+0900: Map: finished flushing the cache to disk.
12/14/2022 04:53:52.915+0900: Queue: persistence switched to disk.
12/14/2022 04:53:52.915+0900: Queue: started flushing the cache to disk.
12/14/2022 04:53:52.915+0900: Queue: finished flushing the cache to disk.
12/14/2022 04:54:00.498+0900: Preparing job 610.32607_1/WAAE_WF0.1/MAIN - 20221214 04540049-0900 WA_AGENT JavaAgent#tcpip@ACE_SCH 610.32607_1/WAAE_WF0.1/MAIN RUN . Data(Args="/job/args/test-job",Command="/autosys/jobs/test.sh") Env(AUTOSERV=ACE,AUTO_JOB_NAME="test-job",AUTORUN="32607-1") User(...) Password(...) MFUser(...) WOBRequestID(8E935B593F791188D2370A1F719CC3E5F888B30516709612404970) GblEnv(AUTOSYS="/SW/CA/WorkloadAutomationAE/autosys",AUTOROOT="/SW/CA/WorkloadAutomationAE",EWAGLOBALPROFILE="/etc/auto.profile") JLErase(TRUE) SpoolErase(TRUE)
12/14/2022 04:54:00.500+0900: Job 610.32607_1/WAAE_WF0.1/MAIN starting
12/14/2022 04:54:00.521+0900: Transmitter: Sending AFM: 20221214 04540000-0900 JavaAgent#tcpip@ACE_SCH OS_COMPONENT 610.32607_1/WAAE_WF0.1/MAIN State EXEC SetStart Status(Executing at WA_AGENT) Jobno(2773183) ChildPid(2773184) JobLogId(D77D815866C982DE96AEAC6CCC91F437EFB35098)
12/14/2022 04:54:11.360+0900: Transmitter: Sending AFM: 20221214 04541100-0900 JavaAgent#tcpip@ACE_SCH OS_COMPONENT 610.32607_1/WAAE_WF0.1/MAIN State COMPLETE Cmpc(0) SetEnd
12/14/2022 04:54:11.361+0900: Job 610.32607_1/WAAE_WF0.1/MAIN has finished with exit code 0
12/14/2022 04:54:11.361+0900: Map: Garbage collection starts
Additional Information
The agent parameter "agent.resourcemon.threshold.disk.critical.shutdown=true" can be set in the agentparm.txt file for the agent to shutdown after the disk critical threshold limit.
The agent needs to be restarted manually to bring it back after ensuring the sufficient disk space.
Feedback
