Skip to main content
P
petrhribal
Participant
December 11, 2012
Question

Core no longer active (x-status=2581223)

  • December 11, 2012
  • 2 replies
  • 2746 views

Good evening.

I would like to ask you for a little help with solving following issue. We've been running AMS_5_0_1_r1076 for last three days with almost no traffic - server has been deployed just for a testing purpose and only developers has been accessing to this running instance. For some weird reason is the running AMS server always shutting down at about ~20 min after last client connection to "live stream application" has been closed. We use standard live app that is distributed with the AMS. I know there is some configuration parameter that influences maximum application idle time before it is undeployed from the server, therefore I've changed this value in Application.xml as you can see below.

Application.xml

<Application>

    <StreamManager>

        <VirtualDirectory>

              <!-- Specifies application specific virtual directory mapping for streams.   -->

            <Streams>/;${LIVE_DIR}</Streams>

        </VirtualDirectory>

    </StreamManager>

   

    <Client>

        <Bandwidth>

            <!-- Specified in bytes/sec -->

            <ServerToClient>2500000</ServerToClient>

            <!-- Specified in bytes/sec -->

            <ClientToServer>2500000</ClientToServer>

        </Bandwidth>

        <MsgQueue>

            <Live>

                <!-- Drop live audio if audio q exceeds time specified. time in milliseconds -->

                <MaxAudioLatency>2000</MaxAudioLatency>

                <!-- Default buffer length in millisecond for live audio and video queue. -->

                <MinBufferTime>2000</MinBufferTime>

            </Live>

            <Recorded>

                <!-- Default buffer length in millisecond for live audio and video, value cannot be set below this by Flash player. -->

                <MinBufferTime>2000</MinBufferTime>

            </Recorded>

            <Server>

                <!-- Ratio of the buffer length used by server side stream -->

                <!-- to live buffer.  The value is between 0 and 1.  To    -->

                <!-- avoid break up of audio, the ratio should not be more -->

                <!-- than 0.5 of the live buffer.                          -->

                <BufferRatio>0.5</BufferRatio>

            </Server>

        </MsgQueue>

    </Client>

    <!-- VZ.CZ -->

    <ScriptEngine>

        <RuntimeSize>30720</RuntimeSize>

    </ScriptEngine>

    <!-- Never unload application on idle -->

    <MaxAppIdleTime>-1</MaxAppIdleTime>

    <Process>

        <LifeTime>3600</LifeTime>

        <MaxFailures>2</MaxFailures>

        <RecoveryTime>10</RecoveryTime>

    </Process>

    <LoadOnStartup>true</LoadOnStartup>

    <!-- Automatically close idle (not responding) clients -->

    <AutoCloseIdleClients enable="true">

        <!-- Each 60s -->

            <CheckInterval>60</CheckInterval>

        <!-- 10 min -->

            <MaxIdleTime>600</MaxIdleTime>

    </AutoCloseIdleClients>

</Application>

At the moment the only clue which gives me some info what really happens with the server is  (x-status=2581223) from master.00.log file.
...

#Date: 2012-12-09

#Fields: date    time    x-pid    x-status    x-ctx    x-comment

2012-12-09    04:27:09    1059    (i)2581173    Host: centurion IPv4: 193.179.245.194    -

2012-12-09    04:27:09    1059    (i)2571011    Server starting...    -

2012-12-09    04:27:11    1059    (i)2581413    /opt/adobe/ams/Apache2.2/bin/httpd -f ./conf/httpd.conf -d "/opt/adobe/ams/Apache2.2" -k start returned 0: [Sun Dec 09 04:27:09 2012] [info] mod_jithttp - AMS installation path: "/opt/adobe/ams/"

httpd: Could not reliably determine the server's fully qualified domain name, using 193.179.245.194 for ServerName    -

2012-12-09    04:27:11    1059    (i)2581413    /opt/adobe/ams/Apache2.2/bin/htcacheclean -n -t -i -p/opt/adobe/ams/Apache2.2/cacheroot -d5 -l1024K returned 0:     -

2012-12-09    04:27:11    1059    (i)2581224    Edge (1169) started, arguments : -edgeports ":1935" -coreports "localhost:19350" -conf "/opt/adobe/ams/conf/Server.xml" -adaptor "_defaultRoot_" -name "_defaultRoot__edge1" -edgename "edge1".    -

2012-12-09    04:27:11    1059    (i)2581221    Core (1173) started, arguments : -adaptor "_defaultRoot_" -vhost  -app  -inst  -tag  -console  -conf "/opt/adobe/ams/conf/Server.xml" -name "_defaultRoot_::::".    -

2012-12-09    04:27:11    1059    (i)2571111    Server started (/opt/adobe/ams/conf/Server.xml).    -

2012-12-09    04:57:36    1059    (i)2581223    Core (1173) is no longer active.  

...

Log file edge.00.log contains following report

#Fields: datetimex-pidx-statusx-ctxx-comment
2012-12-0904:27:111169(i)2581173Host: centurion IPv4: 193.179.245.194-
2012-12-0904:27:111169(i)2631174Listener started ( _defaultRoot__edge1 ) : localhost:19350/v4-
2012-12-0904:27:121169(i)2631174Listener started ( _defaultRoot__edge1 ) : 1935/v4-
2012-12-0904:27:131169(i)2631174Listener started ( _defaultRoot__edge1 ) : 127.0.0.1:19351 (rtmfp-core)/v4-
2012-12-0904:27:131169(i)2631174Listener started ( _defaultRoot__edge1 ) : 193.179.245.194:19351 (rtmfp-core)/v4-
2012-12-0904:27:131169(i)2631509Public rtmfp-core addresses for listener _defaultRoot__edge1 are: 127.0.0.1:19351;193.179.245.194:19351-
2012-12-0904:27:131169(i)2581252Registering core (1173).-
2012-12-0904:27:131169(i)2631174Listener started ( _defaultRoot__edge1 ) : 127.0.0.1:1935 (rtmfp)/v4-
2012-12-0904:27:131169(i)2631174Listener started ( _defaultRoot__edge1 ) : 193.179.245.194:1935 (rtmfp)/v4-
2012-12-0904:57:161169(i)2581250Edge disconnected from core (1173).

Content of admin.00.log file:

2012-12-0904:27:1219375(i)2581241Connection to admin received.-
2012-12-0904:27:1219375(i)2581243Connection from core 1173 received.-
2012-12-0904:27:1219375(i)2581244Connection from core 1173 accepted.-
2012-12-0904:57:2219375(i)2581242Core (1173) disconnected : _defaultRoot_:_defaultVHost_:::.-

core.00.log

#Date: 2012-12-09

#Fields: date    time    x-pid    x-status    x-ctx    x-comment

2012-12-09    04:27:12    1173    (i)2581237    Starting admin app on core (1173).    -

2012-12-09    04:27:12    1173    (i)2581238    Core (1173) connecting to admin.    -

2012-12-09    04:27:12    1173    (i)2581231    Core (1173) connected to admin.    -

2012-12-09    04:27:12    1173    (i)2581234    Core (1173) connection to admin accepted.    -

2012-12-09    04:27:12    1173    (i)2631174    Listener started ( _defaultRoot_ ) : 127.0.0.1:19350 (rtmfp-core)/v4    -

2012-12-09    04:27:12    1173    (i)2631174    Listener started ( _defaultRoot_ ) : 193.179.245.194:19350 (rtmfp-core)/v4    -

2012-12-09    04:27:12    1173    (i)2631509    Public rtmfp-core addresses for listener _defaultRoot_ are: 127.0.0.1:19350;193.179.245.194:19350    -

2012-12-09    04:27:13    1173    (i)2581246    Core (1173) sending register cmd to edge.    -

2012-12-09    04:57:16    1173    (i)2581247    Core (1173) disconnected from edge.    -

2012-12-09    04:57:22    1173    (i)2581233    Core (1173) disconnecting from admin: 200.    -

access.00.log

#Date: 2012-12-09

#Fields: x-event    x-category    date    time    tz    x-ctx    s-ip    x-pid    x-cpu-load    x-mem-load    x-adaptor    x-vhost    x-app    x-appinst    x-duration    x-status    c-ip    c-proto    c-proto-ver    s-uri    cs-uri-stem    cs-uri-query    c-referrer    c-user-agent    c-client-id    cs-bytes    sc-bytes    c-connect-type    x-sname    x-sname-query    x-suri-query    x-suri-stem    x-suri    x-file-name    x-file-ext    x-file-size    x-file-length    x-spos    c-spos    cs-stream-bytes    sc-stream-bytes    x-service-name    x-sc-qos-bytes    x-comment    x-eid    x-sid    x-trans-sname    x-trans-sname-query    x-trans-file-ext    x-trans-mode    x-soffset    x-codec-type    x-codec    x-plugin    x-page-url    x-smax-rec-size    x-smax-rec-duration    x-forwarded-for

server-start    server    2012-12-09    04:27:11    CET    -    -    1173    0    2    -    -    -    -    -    -    -    -    -    -    --    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    --    -    -    -    -    -    -    -    -    -    -    -    -

app-start    application    2012-12-09    04:27:12    CET    live    -    1173    -    -    _defaultRoot_    _defaultVHost_    live    _definst_    -    -    --    -    -    -    -    -    -    -    0    0    -    -    -    -    -    -    -    -    -    -    -    -    -    --    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -

vhost-start    vhost    2012-12-09    04:27:12    CET    _defaultVHost_    -    1173    0    2    _defaultRoot_    _defaultVHost_    -    -    -    -    -    --    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    --    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -

app-start    application    2012-12-09    04:27:53    CET    vod    -    1173    -    -    _defaultRoot_    _defaultVHost_    vod    _definst_    -    -    --    -    -    -    -    -    -    -    0    0    -    -    -    -    -    -    -    -    -    -    -    -    -    --    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -

connect-pending    session    2012-12-09    04:27:53    CET    81.201.60.245    193.179.245.194    1173    99    2    _defaultRoot_    _defaultVHost_    vod    _definst_    0    100    81.201.60.245    rtmp    -    rtmp:/vod    rtmp:/vod    -    http://193.179.245.194/swfs/adobedemoplayer_pc.swf    LNX 11,0,1,152    4702111234508538223    3073    3073    normal    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    --    -    -    -    http://193.179.245.194/    -    -    -

connect    session    2012-12-09    04:27:53    CET    81.201.60.245    193.179.245.194    1173    99    2    _defaultRoot_    _defaultVHost_    vod    _definst_    0    200    81.201.60.245    rtmp    -    rtmp:/vod    rtmp:/vod    -    http://193.179.245.194/swfs/adobedemoplayer_pc.swf    LNX 11,0,1,152    4702111234508538223    3073    3073    normal    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    --    -    -    http://193.179.245.194/    -    -    -

play    stream    2012-12-09    04:27:53    CET    sample1_1500kbps.f4v    193.179.245.194    1173    99    2    _defaultRoot_    _defaultVHost_    vod    _definst_    0    200    81.201.60.245    rtmp    -    rtmp:/vod    rtmp:/vod    -    http://193.179.245.194/swfs/adobedemoplayer_pc.swf    LNX 11,0,1,152    4702111234508538223    3162    3450    normal    sample1_1500kbps.f4v    -    -    rtmp:/vod/sample1_1500kbps.f4v    rtmp:/vod/sample1_1500kbps.f4v    /opt/adobe/ams/webroot/vod/sample1_1500kbps.f4v    mp4    19699010    114.660004    0    -    0    0    -    -    -    -    1    -    -    -    -    -    -    -    -    http://193.179.245.194/    -1    -1.000000    -

stop    stream    2012-12-09    04:27:56    CET    sample1_1500kbps.f4v    193.179.245.194    1173    99    2    _defaultRoot_    _defaultVHost_    vod    _definst_    3    408    81.201.60.245    rtmp    -    rtmp:/vod    rtmp:/vod    -    http://193.179.245.194/swfs/adobedemoplayer_pc.swf    LNX 11,0,1,152    4702111234508538223    3197    679613    normal    sample1_1500kbps.f4v    -    -    rtmp:/vod/sample1_1500kbps.f4v    rtmp:/vod/sample1_1500kbps.f4v    /opt/adobe/ams/webroot/vod/sample1_1500kbps.f4v    mp4    19699010    114.660004    7975    -    0    675370    -    3365    -    -    1    -    -    -    -    -    -    -    -    http://193.179.245.194/    -1    -1.000000    -

disconnect    session    2012-12-09    04:27:56    CET    81.201.60.245    193.179.245.194    1173    99    2    _defaultRoot_    _defaultVHost_    vod    _definst_    3    200    81.201.60.245    rtmp    -    rtmp:/vod    rtmp:/vod    -    http://193.179.245.194/swfs/adobedemoplayer_pc.swf    LNX 11,0,1,152    4702111234508538223    3197    679630    normal    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    --    -    -    -    http://193.179.245.194/    -    -    -

app-stop    application    2012-12-09    04:47:15    CET    live    -    1173    -    -    _defaultRoot_    _defaultVHost_    live    _definst_    -    -    --    -    -    -    -    -    -    -    0    0    -    -    -    -    -    -    -    -    -    -    -    -    -    --    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -

app-stop    application    2012-12-09    04:52:15    CET    vod    -    1173    -    -    _defaultRoot_    _defaultVHost_    vod    _definst_    -    -    --    -    -    -    -    -    -    -    3197    679630    -    -    -    -    -    -    -    -    -    -    -    -    -    --    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -

connect-pending    session    2012-12-09    04:57:22    CET    -    127.0.0.1    1173    0    2    _defaultRoot_    _defaultVHost_    -    -    0    100    -    rtmp    -    -    -    -    -    -    4702111234491761007    226674    1192469    normal    -    -    -    -    -    -    -    -    -    -    --    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -

connect    session    2012-12-09    04:57:22    CET    -    127.0.0.1    1173    0    2    _defaultRoot_    _defaultVHost_    -    -    0    400    -    rtmp    --    -    -    -    -    4702111234491761007    226674    1192469    normal    -    -    -    -    -    -    -    -    -    -    -    -    --    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -

disconnect    session    2012-12-09    04:57:22    CET    -    127.0.0.1    1173    0    2    _defaultRoot_    _defaultVHost_    -    -    1810    200    -    rtmp    -    -    -    -    -    -    4702111234491761007    226674    1192469    normal    -    -    -    -    -    -    -    -    -    -    --    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -

vhost-stop    vhost    2012-12-09    04:57:27    CET    _defaultVHost_    -    1173    0    2    _defaultRoot_    _defaultVHost_    -    -    -    -    -    --    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    --    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -

server-stop    server    2012-12-09    04:57:29    CET    -    -    1173    0    2    -    -    -    -    -    -    -    -    -    -    --    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    -    --    -    -    -    -    -    -    -    -    -    -    -    -

And finally this is the application.00.log file

#Date: 2012-12-09

#Fields: date    time    x-pid    x-status    x-ctx    x-comment

2012-12-09    04:27:12    1173    (i)2611173    Application level recording configuration: General[flags: 0, keyframe interval: 0, max size: -1, max length: -1, io buffer size: 0], Fragment[frag duration: 4000, seg duration: 0, duration precision: 1000, allowed drift: 0, frame rate: 100.000000, frames per interval: 1, intervals per frag: 1, frame precision: 0, disk management duration: 0.000000], ContentProtection[enabled=false(overridable)]    -

2012-12-09    04:27:12    1173    (s)2641173    Starting Live Service...    -

2012-12-09    04:27:12    1173    (s)2641173    Found wildcard (*) entry: disabling authentication for HTML file domains     -

2012-12-09    04:27:12    1173    (s)2641173    Found wildcard (*) entry: disabling authentication for SWF file domains     -

2012-12-09    04:27:12    1173    (s)2641173    ...loading completed.    -

2012-12-09    04:27:12    1173    (i)2611173    Application level Protected RTMP configuration: ContentProtection[enabled=false]    -

2012-12-09    04:47:15    1173    (i)2651170    Unloaded application instance live/_definst_    -

Log files provide only a minimal amount of usefull reports to me.

Any idea what could cause such a problem?

Regards,

Petr H.

---

Please pardon my  English, I'm not a native speaker. Thanks.

This topic has been closed for replies.

2 replies

D
dsummers13-TlCUFk
Participating Frequently
December 11, 2012

Sorry hit send too fast..

I was saying I have the standard AMS 5 install and it will run idle for quite some time and never shuts down.

.d

P
petrhribalAuthor
Participant
December 11, 2012

Thank you for your reply.
Well, the server is supposed to never shut down, but it did.

I always started the AMS by an execution of a following command:

cd /path/to/ams/install/root

./server start

Perfoming this action  produces a couple of reports into a file /var/log/messages:

Dec 11 02:15:10 Centos-5-001 Service[2417]: Server starting...

Dec 11 02:15:10 Centos-5-001 Service[2417]: Server started (/opt/adobe/ams/conf/Server.xml).

Dec 11 02:15:10 Centos-5-001 Adaptor[2437]: Listener started ( _defaultRoot__edge1 ) : localhost:19350/v4

Dec 11 02:15:11 Centos-5-001 Adaptor[2437]: Listener started ( _defaultRoot__edge1 ) : 1935/v4

Dec 11 02:15:11 Centos-5-001 Adaptor[2440]: Listener started ( _defaultRoot_ ) : 127.0.0.1:19350 (rtmfp-core)/v4

Dec 11 02:15:11 Centos-5-001 Adaptor[2440]: Listener started ( _defaultRoot_ ) : 193.179.245.194:19350 (rtmfp-core)/v4

Dec 11 02:15:11 Centos-5-001 Adaptor[2440]: Public rtmfp-core addresses for listener _defaultRoot_ are: 127.0.0.1:19350;193.179.245.194:19350

Dec 11 02:15:12 Centos-5-001 Adaptor[2437]: Listener started ( _defaultRoot__edge1 ) : 127.0.0.1:19351 (rtmfp-core)/v4

Dec 11 02:15:12 Centos-5-001 Adaptor[2437]: Listener started ( _defaultRoot__edge1 ) : 193.179.245.194:19351 (rtmfp-core)/v4

Dec 11 02:15:12 Centos-5-001 Adaptor[2437]: Public rtmfp-core addresses for listener _defaultRoot__edge1 are: 127.0.0.1:19351;193.179.245.194:19351

Dec 11 02:15:12 Centos-5-001 Adaptor[2437]: Listener started ( _defaultRoot__edge1 ) : 127.0.0.1:1935 (rtmfp)/v4

Dec 11 02:15:12 Centos-5-001 Adaptor[2437]: Listener started ( _defaultRoot__edge1 ) : 193.179.245.194:1935 (rtmfp)/v4

Whether has been server really initiated and what kind of processes have been performed with it, can be seen with ps aux command:

ps aux | grep ams

root      2417  0.0  0.1 128284  6068 pts/0    Sl   02:15   0:00 ./amsmaster -console

ams       2437  6.0  0.2 156288  8932 pts/0    Sl   02:15   0:01 /opt/adobe/ams/amsedge -edgeports :1935 -coreports localhost:19350 -conf /opt/adobe/ams/conf/Server.xml -adaptor _defaultRoot_ -name _defaultRoot__edge1 -edgename edge1

ams       2440 25.6  0.5 221160 23076 pts/0    Sl   02:15   0:06 /opt/adobe/ams/amscore -adaptor _defaultRoot_ -vhost -app -inst -tag -console -conf /opt/adobe/ams/conf/Server.xml -name _defaultRoot_::::

root      2572  0.0  0.0  61216   728 pts/0    R+   02:15   0:00 grep ams

root     19375  0.0  0.1 221924  7992 ?        Sl   Dec04   0:30 ./amsadmin -console -conf ./conf/Server.xml

wait ~20min ...
When I execute the previous command one more time after ~20 min, I get following output:

ps aux | grep ams

root      2417  0.0  0.1 128280  6128 pts/0    Sl   02:15   0:00 ./amsmaster -console

ams       2437  0.0  0.2 156288  8972 pts/0    Sl   02:15   0:01 /opt/adobe/ams/amsedge -edgeports :1935 -coreports localhost:19350 -conf /opt/adobe/ams/conf/Server.xml -adaptor _defaultRoot_ -name _defaultRoot__edge1 -edgename edge1

root      2597  0.0  0.0  61216   724 pts/0    R+   02:44   0:00 grep ams

root     19375  0.0  0.1 221924  7992 ?        Sl   Dec04   0:30 ./amsadmin -console -conf ./conf/Server.xml

I should also mention that I've updated a value of a configuration parameter CoreExitDelay in a file Server.xml to value '-1', to preserve core being loaded on server even if it idles.

<Master>

        <!-- How often to gc idle cores.                                             -->

        <CoreGC>300</CoreGC>

        <!-- An idle core being gc'd is given at least this much to exit on its own. -->

        <!-- VZ.CZ -->

        <CoreExitDelay>-1</CoreExitDelay>

</Master>

And that is the output after one hour - there is no sign of running adobe server at all


ps aux | grep ams

root      2343  0.0  0.0  61216   724 pts/0    R+   03:24   0:00 grep ams

root     19375  0.0  0.1 221924  7992 ?        Sl   Dec04   0:30 ./amsadmin -console -conf ./conf/Server.xml

A
Anonymous
December 11, 2012

Hi,

This is the expected behaviour of AMS. Once the connection is idle for some time (by default 20 minutes), the amsmaster process shuts down the amscore process. This does not mean that server has shutdown. Once you make a connection to any app, again the amscore process will come up.

Also, for tag <CoreExitDelay>, I am not sure whether -1 is a valid value. For more details about these tags, you can check following link:

http://help.adobe.com/en_US/adobemediaserver/configadmin/WSB283465C-AA74-488c-B3E8-6CAF906CAF0E.2.3.html#WSC4BFC1AD-573A-4a70-ACDD-D67CA8042B36.2.3

 

D
dsummers13-TlCUFk
Participating Frequently
December 11, 2012

Is the server as a whole shutting down? It just the Application(s)?

I know the applications will shutdown when inactive, but I don't think the server itself is ever supposed to.

I have the standard install (AMS 5) and the

.d

Terms & ConditionsAccessibility statement
Using the community Terms of use Privacy Cookie preferences Do not sell or share my personal information ad choicesAdChoices