search

ant-media / Ant-Media-Server

Ant Media Server is a live streaming engine software that provides adaptive, ultra low latency streaming by using WebRTC technology with ~0.5 seconds latency. Ant Media Server is auto-scalable and it can run on-premise or on-cloud.
https://antmedia.io
Other
4.27k stars 627 forks source link

Unexpected shutdown org.mapdb.DBException$VolumeEOF exception #4576

Open SelimEmre opened 1 year ago

SelimEmre commented 1 year ago

Short description

This exception came up during the restart Ant Media Server. I'm not quite sure for reproduce this issue.

Steps to reproduce

  1. I couldn't reproduce it yet

Expected behavior

It shouldn't give exceptions like this

Actual behavior

It gives

Logs

2022-11-09 16:42:56,613 [main] INFO  org.red5.server.Launcher - Ant Media Server Enterprise 2.5.1
2022-11-09 16:42:56,615 [main] INFO  org.red5.server.Launcher - 
                                                             
             `..-:/++oosssyyyyyyyysssoo++/::..`             
        .:+osyyyyysooo++///::::::///++ooosyyyyyso+:.        
     -+syyso/:-.`         ```````          `.-:/osyyy+-     
   .oyyo:.    ``.-:/+oossyyyyyys:`.+o+: `..`      `-+yys.   
   oyy-   `.-:://:::::///++ooo-`-oyo:../sys/`.::.    .yys   
   syy+`                       `.-. -oys/..:oys+:`   :yyy   
   syyyo-`                           `. `+so/.`   `-oyyyy   
   syy+sys+:.`                           ``   `.:+syyoyyy   
   syy``:+syyso`       `..`                 `osyyso:. syy   
   syy`   `.oyy.      :syyso:.`             `yys.`    syy   
   syy`     +yy.      syy:+syys+-`          `yyo      syy   
   syy`     +yy.      yyy  `.:osyso/.`      `yyo      syy   
   syy`     +yy.      yyy      `-/syys+.    `yyo      syy   
   syy`     +yy.      yyy         `./yyy    `yyo      syy   
   syy`     +yy.      yyy       `./oyys/    `yyo      syy   
   syy`     +yy.      yyy    .:+syyo/-`     `yyo      syy   
   syy`     +yy.      yyy`-/syys+:.         `yyo      syy   
   syy`     +yy.      +yyyyyo/.`            `yyo      yyy   
   /yy/     +yy.       -::-`                `yyo     :yy+   
    +yyo:.  +yy.                            `yyo  .-oyy+`   
     .+yyyysyyy.                            `yyysyyyy+-     
        .:/+++/                              :+//:-.        



2022-11-09 16:42:57,036 [main] INFO  o.r.spring.Red5ApplicationContext - setApplicationContext: org.springframework.context.support.FileSystemXmlApplicationContext@55493582, started on Wed Nov 09 16:42:56 UTC 2022
2022-11-09 16:42:57,043 [main] INFO  o.r.spring.Red5ApplicationContext - Red5ApplicationContext init
2022-11-09 16:42:57,213 [main] INFO  org.quartz.impl.StdSchedulerFactory - Using default implementation for ThreadExecutor
2022-11-09 16:42:57,222 [main] INFO  o.quartz.core.SchedulerSignalerImpl - Initialized Scheduler Signaller of type: class org.quartz.core.SchedulerSignalerImpl
2022-11-09 16:42:57,222 [main] INFO  org.quartz.core.QuartzScheduler - Quartz Scheduler v.2.3.2 created.
2022-11-09 16:42:57,222 [main] INFO  org.quartz.simpl.RAMJobStore - RAMJobStore initialized.
2022-11-09 16:42:57,223 [main] INFO  org.quartz.core.QuartzScheduler - Scheduler meta-data: Quartz Scheduler (v2.3.2) 'Red5_Scheduler' with instanceId 'NON_CLUSTERED'
  Scheduler class: 'org.quartz.core.QuartzScheduler' - running locally.
  NOT STARTED.
  Currently in standby mode.
  Number of jobs executed: 0
  Using thread pool 'org.quartz.simpl.SimpleThreadPool' - with 6 threads.
  Using job-store 'org.quartz.simpl.RAMJobStore' - which does not support persistence. and is not clustered.

2022-11-09 16:42:57,223 [main] INFO  org.quartz.impl.StdSchedulerFactory - Quartz scheduler 'Red5_Scheduler' initialized from the specified file : '/usr/local/antmedia/conf/quartz.properties'
2022-11-09 16:42:57,223 [main] INFO  org.quartz.impl.StdSchedulerFactory - Quartz scheduler version: 2.3.2
2022-11-09 16:42:57,223 [main] INFO  org.quartz.core.QuartzScheduler - Scheduler Red5_Scheduler_$_NON_CLUSTERED started.
2022-11-09 16:42:57,725 [main] INFO  io.antmedia.settings.ServerSettings - Using local host address is 51.89.116.109
2022-11-09 16:42:57,737 [main] WARN  i.antmedia.statistic.StatsCollector - Starting heartbeats for the version:2.5.1 and type:Enterprise
2022-11-09 16:42:57,764 [main] INFO  i.a.enterprise.srt.SRTAdaptor - SRT server is starting for port 4200
2022-11-09 16:42:57,766 [main] INFO  i.a.enterprise.srt.SRTAdaptor - SRT server starts listening for port 4200
2022-11-09 16:42:57,766 [main] INFO  i.a.enterprise.srt.SRTAdaptor - SRT epoll is created
2022-11-09 16:42:57,766 [main] INFO  i.a.enterprise.srt.SRTAdaptor - SRT epoll thread is starting
2022-11-09 16:42:57,897 [main] INFO  o.r.spring.Red5ApplicationContext - setApplicationContext: org.springframework.context.support.FileSystemXmlApplicationContext@55493582, started on Wed Nov 09 16:42:56 UTC 2022
2022-11-09 16:42:57,897 [main] INFO  o.r.spring.Red5ApplicationContext - Red5ApplicationContext init
2022-11-09 16:42:57,988 [main] INFO  o.r.s.net.rtmp.RTMPMinaTransport - RTMP will be bound to [0.0.0.0:1935]
2022-11-09 16:42:57,989 [main] INFO  o.r.s.net.rtmp.RTMPMinaTransport - RTMP Mina Transport Settings
Acceptor style: default I/O threads: 16
TCP no-delay: true keep-alive: false
2022-11-09 16:42:58,001 [main] INFO  o.r.s.net.rtmp.RTMPMinaTransport - Traffic class modification is disabled
2022-11-09 16:42:58,001 [main] INFO  o.r.s.net.rtmp.RTMPMinaTransport - Send buffer size: 65536 recv buffer size: 65536 so linger: -1 traffic class: 0
2022-11-09 16:42:58,014 [main] INFO  org.red5.server.ContextLoader - ContextLoader init
2022-11-09 16:42:58,020 [main] INFO  org.red5.server.ContextLoader - Loading: default.context = ${red5.root}/webapps/red5-default.xml => /usr/local/antmedia/webapps/red5-default.xml
2022-11-09 16:42:58,160 [main] INFO  org.red5.server.Context - Deployment type: bootstrap
2022-11-09 16:42:58,168 [main] INFO  org.red5.server.tomcat.WarDeployer - War deployer service created
2022-11-09 16:42:58,170 [main] INFO  org.red5.server.tomcat.WarDeployer - Starting WarDeployer
2022-11-09 16:42:58,171 [main] INFO  org.red5.server.tomcat.WarDeployer - Deploy wars without app start
2022-11-09 16:42:58,233 [main] INFO  org.red5.server.tomcat.TomcatLoader - Loading Tomcat
2022-11-09 16:42:58,233 [main] INFO  org.red5.server.tomcat.TomcatLoader - Server root: /usr/local/antmedia
2022-11-09 16:42:58,233 [main] INFO  org.red5.server.tomcat.TomcatLoader - Config root: /usr/local/antmedia/conf
2022-11-09 16:42:58,246 [main] INFO  org.red5.server.tomcat.TomcatLoader - Application root: /usr/local/antmedia/webapps
2022-11-09 16:42:58,309 [main] INFO  org.red5.server.tomcat.TomcatLoader - Starting Tomcat servlet engine
2022-11-09 16:42:58,440 [main] WARN  o.a.c.core.AprLifecycleListener - This listener must only be nested within Server elements, but is in [Connector].
2022-11-09 16:42:58,443 [main] INFO  o.a.c.core.AprLifecycleListener - The Apache Tomcat Native library which allows using OpenSSL was not found on the java.library.path: [/usr/local/antmedia/lib/native]
2022-11-09 16:42:58,447 [main] INFO  o.a.c.http11.Http11Nio2Protocol - Initializing ProtocolHandler ["http-nio2-0.0.0.0-5080"]
2022-11-09 16:42:58,485 [main] INFO  o.a.catalina.core.StandardService - Starting service [Tomcat]
2022-11-09 16:42:58,486 [main] INFO  o.a.catalina.core.StandardEngine - Starting Servlet engine: [Apache Tomcat/8.5.82]
2022-11-09 16:42:58,538 [0.0.0.0-startStop-1] INFO  o.a.catalina.loader.WebappLoader - Unknown loader jdk.internal.loader.ClassLoaders$AppClassLoader@6a6824be class jdk.internal.loader.ClassLoaders$AppClassLoader
2022-11-09 16:42:58,563 [0.0.0.0-startStop-1] INFO  o.a.catalina.startup.ContextConfig - No global web.xml found
2022-11-09 16:42:58,651 [0.0.0.0-startStop-1] INFO  o.a.c.c.C.[.[0.0.0.0].[/] - No Spring WebApplicationInitializer types detected on classpath
2022-11-09 16:42:58,673 [0.0.0.0-startStop-1] INFO  ROOT - Starting up context: root
2022-11-09 16:42:59,363 [0.0.0.0-startStop-1] ERROR o.g.j.s.s.SpringComponentProvider - Spring context lookup failed, skipping spring component provider initialization.
2022-11-09 16:42:59,687 [0.0.0.0-startStop-1] INFO  o.a.catalina.loader.WebappLoader - Unknown loader jdk.internal.loader.ClassLoaders$AppClassLoader@6a6824be class jdk.internal.loader.ClassLoaders$AppClassLoader
2022-11-09 16:42:59,768 [0.0.0.0-startStop-1] INFO  o.a.c.c.C.[.[0.0.0.0].[/LiveApp] - No Spring WebApplicationInitializer types detected on classpath
2022-11-09 16:42:59,781 [0.0.0.0-startStop-1] INFO  ROOT - Starting up context: LiveApp
2022-11-09 16:42:59,912 [0.0.0.0-startStop-1] ERROR o.g.j.s.s.SpringComponentProvider - Spring context lookup failed, skipping spring component provider initialization.
2022-11-09 16:43:00,006 [0.0.0.0-startStop-1] INFO  o.a.catalina.loader.WebappLoader - Unknown loader jdk.internal.loader.ClassLoaders$AppClassLoader@6a6824be class jdk.internal.loader.ClassLoaders$AppClassLoader
2022-11-09 16:43:00,101 [0.0.0.0-startStop-1] INFO  o.a.c.c.C.[.[.0.0.0].[/WebRTCAppEE] - No Spring WebApplicationInitializer types detected on classpath
2022-11-09 16:43:00,104 [0.0.0.0-startStop-1] INFO  ROOT - Starting up context: WebRTCAppEE
2022-11-09 16:43:00,212 [0.0.0.0-startStop-1] ERROR o.g.j.s.s.SpringComponentProvider - Spring context lookup failed, skipping spring component provider initialization.
2022-11-09 16:43:00,311 [main] INFO  o.a.c.http11.Http11Nio2Protocol - Starting ProtocolHandler ["http-nio2-0.0.0.0-5080"]
2022-11-09 16:43:00,315 [main] INFO  org.red5.server.tomcat.TomcatLoader - Context initialized:  path: /usr/local/antmedia/webapps/root/
2022-11-09 16:43:00,315 [main] INFO  org.red5.server.tomcat.TomcatLoader - Spring parent context key: default.context
2022-11-09 16:43:00,320 [main] INFO  org.red5.server.tomcat.TomcatLoader - Context initialized: /LiveApp path: /usr/local/antmedia/webapps/LiveApp/
2022-11-09 16:43:00,320 [main] INFO  org.red5.server.tomcat.TomcatLoader - Spring parent context key: default.context
2022-11-09 16:43:00,320 [main] INFO  org.red5.server.tomcat.TomcatLoader - Context initialized: /WebRTCAppEE path: /usr/local/antmedia/webapps/WebRTCAppEE/
2022-11-09 16:43:00,320 [main] INFO  org.red5.server.tomcat.TomcatLoader - Spring parent context key: default.context
2022-11-09 16:43:00,490 [Loader:] INFO  org.red5.server.Context - Deployment type: bootstrap
2022-11-09 16:43:00,571 [Loader:] INFO  org.red5.server.scope.WebScope - Set server [Server@469903dmap[[empty]]]
2022-11-09 16:43:00,586 [Loader:] INFO  org.red5.server.Server - Add mapping global: default host:  context: root
2022-11-09 16:43:00,589 [Loader:] INFO  org.red5.server.scope.WebScope - Webscope already registered; remove the 'init-method' from your 'web.scope' bean to prevent this message in the future.
2022-11-09 16:43:00,826 [Loader:/LiveApp] INFO  org.red5.server.Context - Deployment type: bootstrap
2022-11-09 16:43:01,220 [Loader:/LiveApp] INFO  i.a.datastore.db.DataStoreFactory - Used Datastore:mapdb  db name:liveapp
2022-11-09 16:43:01,231 [Loader:/LiveApp] INFO  org.red5.server.scope.WebScope - Set server [Server@469903dmap['/root' -> 'default']]
2022-11-09 16:43:01,231 [Loader:/LiveApp] INFO  org.red5.server.Server - Add mapping global: default host:  context: LiveApp
2022-11-09 16:43:01,233 [Loader:/LiveApp] INFO  i.a.AntMediaApplicationAdapter - Initialized file is created in LiveApp
2022-11-09 16:43:01,236 [Loader:/LiveApp] INFO  i.a.enterprise.webrtc.WebRTCAdaptor - setting excessive bandwidth algorithm enabled:false 
2022-11-09 16:43:01,236 [Loader:/LiveApp] INFO  i.a.AntMediaApplicationAdapter - LiveApp started
2022-11-09 16:43:01,248 [vert.x-eventloop-thread-1] INFO  i.a.AntMediaApplicationAdapter - Stream source size: 0
2022-11-09 16:43:01,248 [vert.x-eventloop-thread-1] INFO  i.a.s.StreamFetcherManager - StreamFetcherSchedule job name 10
2022-11-09 16:43:01,367 [Loader:/WebRTCAppEE] INFO  org.red5.server.Context - Deployment type: bootstrap
2022-11-09 16:43:01,384 [Loader:/WebRTCAppEE] INFO  i.a.datastore.db.DataStoreFactory - Used Datastore:mapdb  db name:webrtcappee
2022-11-09 16:43:01,388 [Loader:/WebRTCAppEE] INFO  org.red5.server.scope.WebScope - Set server [Server@469903dmap['/root' -> 'default', '/LiveApp' -> 'default']]
2022-11-09 16:43:01,388 [Loader:/WebRTCAppEE] INFO  org.red5.server.Server - Add mapping global: default host:  context: WebRTCAppEE
2022-11-09 16:43:01,389 [Loader:/WebRTCAppEE] INFO  i.a.AntMediaApplicationAdapter - Initialized file is created in WebRTCAppEE
2022-11-09 16:43:01,390 [Loader:/WebRTCAppEE] INFO  i.a.enterprise.webrtc.WebRTCAdaptor - setting excessive bandwidth algorithm enabled:false 
2022-11-09 16:43:01,390 [Loader:/WebRTCAppEE] INFO  i.a.AntMediaApplicationAdapter - WebRTCAppEE started
2022-11-09 16:43:01,400 [vert.x-eventloop-thread-1] INFO  i.a.AntMediaApplicationAdapter - Stream source size: 0
2022-11-09 16:43:01,400 [vert.x-eventloop-thread-1] INFO  i.a.s.StreamFetcherManager - StreamFetcherSchedule job name 18
2022-11-09 16:43:58,171 [pool-4-thread-1] INFO  org.red5.server.tomcat.WarDeployer - Deploy wars with app start
2022-11-09 16:44:24,599 [Thread-8] INFO  i.a.enterprise.srt.SRTAdaptor - SRT socket is closed
2022-11-09 16:44:24,600 [Thread-8] INFO  i.a.enterprise.srt.SRTAdaptor - SRT epoll is released
2022-11-09 16:44:24,608 [Thread-8] INFO  i.a.enterprise.srt.SRTAdaptor - SRT clean up is successful
2022-11-09 16:44:24,608 [Thread-8] INFO  i.a.e.webrtc.WebRTCApplication - LiveApp is closing streams
2022-11-09 16:44:24,630 [Thread-8] ERROR i.a.shutdown.AMSShutdownManager - org.mapdb.DBException$VolumeEOF: Get/Set beyond file size. Requested offset: 6291312, volume size: 9437184
    at org.mapdb.volume.ByteBufferVol.getSlice(ByteBufferVol.java:43)
    at org.mapdb.volume.ByteBufferVol.getDataInput(ByteBufferVol.java:136)
    at org.mapdb.volume.ByteBufferVol.getDataInput(ByteBufferVol.java:18)
    at org.mapdb.StoreDirect.get(StoreDirect.kt:545)
    at org.mapdb.BTreeMap.getNode(BTreeMap.kt:800)
    at org.mapdb.BTreeMap.access$getNode(BTreeMap.kt:72)
    at org.mapdb.BTreeMap$BTreeIterator.advanceFrom(BTreeMap.kt:1031)
    at org.mapdb.BTreeMap$BTreeIterator.<init>(BTreeMap.kt:1016)
    at org.mapdb.BTreeMap$valueIterator$1.<init>(BTreeMap.kt:1223)
    at org.mapdb.BTreeMap.valueIterator(BTreeMap.kt:1223)
    at org.mapdb.BTreeMap$values$1.iterator(BTreeMap.kt:999)
    at io.antmedia.datastore.db.DataStore.getConferenceRoomList(DataStore.java:201)
    at io.antmedia.datastore.db.MapBasedDataStore.getConferenceRoomList(MapBasedDataStore.java:229)
    at io.antmedia.enterprise.webrtc.WebRTCApplication.deleteZombiRooms(WebRTCApplication.java:201)
    at io.antmedia.enterprise.webrtc.WebRTCApplication.stopApplication(WebRTCApplication.java:183)
    at io.antmedia.AntMediaApplicationAdapter.serverShuttingdown(AntMediaApplicationAdapter.java:982)
    at io.antmedia.shutdown.AMSShutdownManager.notifyShutdown(AMSShutdownManager.java:40)
    at org.red5.server.service.ShutdownServer$2.run(ShutdownServer.java:164)

2022-11-09 16:44:24,631 [Thread-8] INFO  i.a.e.webrtc.WebRTCApplication - WebRTCAppEE is closing streams
2022-11-09 16:44:24,632 [Thread-8] INFO  i.a.e.webrtc.WebRTCApplication - Checking if total number of live stream(0) in WebRTC Adaptor is zero for app:WebRTCAppEE
2022-11-09 16:44:24,632 [Thread-8] INFO  i.a.e.webrtc.WebRTCApplication - Checking if total number of webrtc viewers(0) in WebRTC Adaptor is zero for app:WebRTCAppEE
2022-11-09 16:44:24,633 [Thread-8] ERROR i.a.shutdown.AMSShutdownManager - org.mapdb.DBException$VolumeEOF: Get/Set beyond file size. Requested offset: 11953184, volume size: 15728640
    at org.mapdb.volume.ByteBufferVol.getSlice(ByteBufferVol.java:43)
    at org.mapdb.volume.ByteBufferVol.getDataInput(ByteBufferVol.java:136)
    at org.mapdb.volume.ByteBufferVol.getDataInput(ByteBufferVol.java:18)
    at org.mapdb.StoreDirect.get(StoreDirect.kt:545)
    at org.mapdb.BTreeMap.getNode(BTreeMap.kt:800)
    at org.mapdb.BTreeMap.access$getNode(BTreeMap.kt:72)
    at org.mapdb.BTreeMap$BTreeIterator.advanceFrom(BTreeMap.kt:1031)
    at org.mapdb.BTreeMap$BTreeIterator.advance(BTreeMap.kt:1050)
    at org.mapdb.BTreeMap$valueIterator$1.next(BTreeMap.kt:1229)
    at io.antmedia.datastore.db.DataStore.getActiveBroadcastCount(DataStore.java:668)
    at io.antmedia.datastore.db.MapBasedDataStore.getActiveBroadcastCount(MapBasedDataStore.java:214)
    at io.antmedia.datastore.db.DataStore.getLocalLiveBroadcastCount(DataStore.java:952)
    at io.antmedia.AntMediaApplicationAdapter.waitUntilLiveStreamsStopped(AntMediaApplicationAdapter.java:915)
    at io.antmedia.enterprise.webrtc.WebRTCApplication.stopApplication(WebRTCApplication.java:186)
    at io.antmedia.AntMediaApplicationAdapter.serverShuttingdown(AntMediaApplicationAdapter.java:982)
    at io.antmedia.shutdown.AMSShutdownManager.notifyShutdown(AMSShutdownManager.java:40)
    at org.red5.server.service.ShutdownServer$2.run(ShutdownServer.java:164)
mekya commented 1 year ago

Nothing to do for now. Please update the issue when you have a reproduce scenario