Ts3audiobot: Bot Timeout

[robotrono]

I get this timeout:

[ERROR] FATAL UNHANDLED EXCEPTION: System.NullReferenceException: Object reference not set to an instance of an object
  at TS3AudioBot.Ts3Full.AudioSend () [0x0007a] in <f39f29301a564c90a90ac1e149d9b50a>:0
  at TS3AudioBot.Helper.TickPool.Tick () [0x00072] in <f39f29301a564c90a90ac1e149d9b50a>:0
  at System.Threading.ThreadHelper.ThreadStart_Context (System.Object state) [0x00017] in <8f2c484307284b51944a1a13a14c0266>:0
  at System.Threading.ExecutionContext.RunInternal (System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, System.Object state, System.Boolean preserveSyncCtx) [0x0008d] in <8f2c484307284b51944a1a13a14c0266>:0
  at System.Threading.ExecutionContext.Run (System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, System.Object state, System.Boolean preserveSyncCtx) [0x00000] in <8f2c484307284b51944a1a13a14c0266>:0
  at System.Threading.ExecutionContext.Run (System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, System.Object state) [0x00031] in <8f2c484307284b51944a1a13a14c0266>:0
  at System.Threading.ThreadHelper.ThreadStart () [0x0000b] in <8f2c484307284b51944a1a13a14c0266>:0

[07:35:55]  Debug: Bot disconnected. Reason: Timeout
[07:35:55]Warning: -1: the command failed to execute: Connection Closed (missing permission:-1)
[07:35:55]   Info: Exiting...
[07:35:55]   Info: Closing Mediaplayer...
[07:35:55]  Debug: AF stop old
[07:35:56]Warning: -1: the command failed to execute: Connection closed (missing permission:-1)
[07:35:56]   Info: Closing QueryConnection...
[07:35:56]   Info: Closing QueryConnection...

[Splamy]

Do the bot and the teamspeak server run on the same system?

[robotrono]

Yes, same vps.

[Splamy]

would wou mind letting the bot run in debug mode in case something happens in future? It might be a slight decrease in performance but the stacktrace is also more useful with line numbers.

For that you'd have to compile and run the bot that way:

1) xbuild /p:Configuration=Debug TS3AudioBot.sln
2) mono --debug TS3AudioBot.exe -q

(or however you start the bot, the --debug part is the important part for mono.)

[robotrono]

Ok done. Thanks!

[robotrono]

Same problem:

[13:14:52]  Debug: AF ar start: Youtube ID:FBEE-t-uyI0
[13:14:52]  Debug: AF set volume: 5
[13:18:45]  Debug: YT avail codecs: hd720 @ MP4, medium @ WEBM, medium @ MP4, small @ ThreeGP, small @ ThreeGP, audio/mp4; codecs="mp4a.40.2" @ M4A, audio/webm; codecs="vorbis" @ WEBM, audio/webm; codecs="opus" @ WEBM, audio/webm; codecs="opus" @ WEBM, audio/webm; codecs="opus" @ WEBM, 
[13:18:46]Warning: TH Web error: [403] Forbidden
[13:18:46]  Debug: YT Ruined!
[13:18:47]  Debug: YT Saved!
[13:18:47]  Debug: AF stop old
[13:18:47]  Debug: AF ar start: Youtube ID:J1b5qkfUpM0
[13:18:47]  Debug: AF set volume: 5
[13:22:48]  Debug: YT avail codecs: hd720 @ MP4, medium @ WEBM, medium @ MP4, small @ ThreeGP, small @ ThreeGP, audio/mp4; codecs="mp4a.40.2" @ M4A, audio/webm; codecs="vorbis" @ WEBM, audio/webm; codecs="opus" @ WEBM, audio/webm; codecs="opus" @ WEBM, audio/webm; codecs="opus" @ WEBM, 
[13:22:48]Warning: TH Web error: [403] Forbidden
[13:22:48]  Debug: YT Ruined!
[13:22:50]  Debug: YT Saved!
[13:22:50]  Debug: AF stop old
[13:22:50]  Debug: AF ar start: Youtube ID:T3bxbVGWy5k
[13:22:50]  Debug: AF set volume: 5
[13:22:55]  Debug: Bot disconnected. Reason: Timeout
[13:22:55]   Info: Exiting...
[13:22:55]Warning: -1: the command failed to execute: Connection Closed (missing permission:-1)
[13:22:55]   Info: Closing Mediaplayer...
[13:22:55]  Debug: AF stop old
[13:22:55]Warning: -1: the command failed to execute: Connection closed (missing permission:-1)
[13:22:55]   Info: Closing QueryConnection...
[13:22:55]   Info: Closing QueryConnection...

[Splamy]

This timeout seems very wrong, I will write some custom debugging parts and open another branch for it, I will @-ping you here when it's done so you can try it then. Sorry for all the inconveniances, and thanks for your time and help.

[robotrono]

Thanks to you @Splamy, this bot has potential!

[Splamy]

A quick update here, I can not work for another ~5 days, since I have to learn for my finals :/
Just so you know...

[robotrono]

It's ok! Ganbare in your finals!

[robotrono]

I just saw the new branch, should I try that branch? @Splamy

[Splamy]

You can always try, it might get some improvements, but it also might do nothing.
The patch was mainly to improve packet handlig and prevent jam when a lot of packets drop

[Splamy]

Just a quick update here, I haven't forgotten this issue :P but after spending many hours fiddeling in the ts3client code I have decided to rework the base structure entirely.
This means I will not create the debug branch for this since I hope the rework will fix a few things.
If the problem persists afterwards I will try it with the debug branch.

[robotrono]

Thanks so much, btw I noticed the following, the bot does not disconnect if this dont play music 24/7. The bot remains connected if it does not play music.

[Splamy]

@robotrono I _finally_ found and fixed the problem why the bot randomly times out after a certain time. Please try out the latest dev branch and tell me it it worked (after a few days of stable operation).

[robotrono]

@Splamy I get this error:

/home/akira/Documents/TS3AudioBot/TS3AudioBot.sln (default targets) ->
(Build target) ->
/home/akira/Documents/TS3AudioBot/TS3AudioBot/TS3AudioBot.csproj (default targets) ->
/usr/lib/mono/xbuild/14.0/bin/Microsoft.CSharp.targets (CoreCompile target) ->

    Helper/ConfigFile.cs(366,4): error CS0012: The type `System.Attribute' is defined in an assembly that is not referenced. Consider adding a reference to assembly `System.Runtime, Version=4.0.20.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a'

[robotrono]

Sorry, Fixed.

Well I will back with results in 5 days. Thanks @Splamy

[robotrono]

@Splamy This is ok? I'm trying to play a playlist from Youtube, but this only works for the first song, the next song cant play and the bot stop.

[06:07:16] Debug: Connection to song lost, retrying at 00:02:58.7940000

In chat I get this:

"AudioBot": An unexpected error occured: Specified cast is not valid.

Console:

[06:04:11]  Debug: MB Got message from Akira: !list show
[06:04:16]  Debug: MB Got message from Akira: !list play
[06:04:17]  Debug: AF stop old
[06:04:17]  Debug: AF ar start: Youtube ID:WUbHQ0lf64o
[06:04:17]  Debug: AF set volume: 5
[06:04:17]  Error: MB Unexpected command error: MSG: Specified cast is not valid.
TYPE:InvalidCastException
STACK:  at (wrapper castclass) System.Object:__castclass_with_cache (object,intptr,intptr)
  at LiteDB.PageService.GetPage[T] (System.UInt32 pageID) [0x00056] in <fd3cfe54fa504c7989678d84ffcd090b>:0
  at LiteDB.DataService.GetBlock (LiteDB.PageAddress blockAddress) [0x00000] in <fd3cfe54fa504c7989678d84ffcd090b>:0
  at LiteDB.DataService.Read (LiteDB.PageAddress blockAddress) [0x00000] in <fd3cfe54fa504c7989678d84ffcd090b>:0
  at LiteDB.LiteEngine+<Find>d__52.MoveNext () [0x0013d] in <fd3cfe54fa504c7989678d84ffcd090b>:0
  at LiteDB.LiteCollection`1+<Find>d__17[T].MoveNext () [0x000fc] in <fd3cfe54fa504c7989678d84ffcd090b>:0
  at System.Linq.Enumerable.FirstOrDefault[TSource] (System.Collections.Generic.IEnumerable`1[T] source) [0x0003e] in <2392cff65f724abaaed9de072f62bc4a>:0
  at LiteDB.LiteCollection`1[T].FindOne (System.Linq.Expressions.Expression`1[TDelegate] predicate) [0x00018] in <fd3cfe54fa504c7989678d84ffcd090b>:0
  at TS3AudioBot.History.HistoryManager.FindByUniqueId (System.String uniqueId) [0x00084] in <bbaf56f358a145f5912928023124867e>:0
  at TS3AudioBot.History.HistoryManager.Store (TS3AudioBot.History.HistorySaveData saveData) [0x00026] in <bbaf56f358a145f5912928023124867e>:0
  at TS3AudioBot.History.HistoryManager.LogAudioResource (TS3AudioBot.History.HistorySaveData saveData) [0x00000] in <bbaf56f358a145f5912928023124867e>:0
  at TS3AudioBot.PlayManager.Play (TS3AudioBot.InvokerData invoker, TS3AudioBot.ResourceFactories.PlayResource play, TS3AudioBot.MetaData meta) [0x0009b] in <bbaf56f358a145f5912928023124867e>:0
  at TS3AudioBot.PlayManager.Play (TS3AudioBot.InvokerData invoker, TS3AudioBot.ResourceFactories.AudioResource ar, TS3AudioBot.MetaData meta) [0x00035] in <bbaf56f358a145f5912928023124867e>:0
  at TS3AudioBot.PlayManager.Play (TS3AudioBot.InvokerData invoker, TS3AudioBot.PlaylistItem item) [0x000b1] in <bbaf56f358a145f5912928023124867e>:0
  at TS3AudioBot.MainBot.CommandListPlay (TS3AudioBot.CommandSystem.ExecutionInformation info, System.Nullable`1[T] index) [0x0008f] in <bbaf56f358a145f5912928023124867e>:0
  at (wrapper managed-to-native) System.Reflection.MonoMethod:InternalInvoke (System.Reflection.MonoMethod,object,object[],System.Exception&)
  at System.Reflection.MonoMethod.Invoke (System.Object obj, System.Reflection.BindingFlags invokeAttr, System.Reflection.Binder binder, System.Object[] parameters, System.Globalization.CultureInfo culture) [0x00038] in <dbb16e0bacdc4a0f87478e401bc29b6c>:0
--- End of stack trace from previous location where exception was thrown ---
  at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw () [0x0000c] in <dbb16e0bacdc4a0f87478e401bc29b6c>:0
  at TS3AudioBot.CommandSystem.FunctionCommand.ExecuteFunction (System.Object[] parameters) [0x00020] in <bbaf56f358a145f5912928023124867e>:0
  at TS3AudioBot.CommandSystem.FunctionCommand.Execute (TS3AudioBot.CommandSystem.ExecutionInformation info, System.Collections.Generic.IEnumerable`1[T] arguments, System.Collections.Generic.IEnumerable`1[T] returnTypes) [0x00145] in <bbaf56f358a145f5912928023124867e>:0
  at TS3AudioBot.CommandSystem.BotCommand.Execute (TS3AudioBot.CommandSystem.ExecutionInformation info, System.Collections.Generic.IEnumerable`1[T] arguments, System.Collections.Generic.IEnumerable`1[T] returnTypes) [0x00086] in <bbaf56f358a145f5912928023124867e>:0
  at TS3AudioBot.CommandSystem.CommandGroup.Execute (TS3AudioBot.CommandSystem.ExecutionInformation info, System.Collections.Generic.IEnumerable`1[T] arguments, System.Collections.Generic.IEnumerable`1[T] returnTypes) [0x000bd] in <bbaf56f358a145f5912928023124867e>:0
  at TS3AudioBot.CommandSystem.CommandGroup.Execute (TS3AudioBot.CommandSystem.ExecutionInformation info, System.Collections.Generic.IEnumerable`1[T] arguments, System.Collections.Generic.IEnumerable`1[T] returnTypes) [0x000bd] in <bbaf56f358a145f5912928023124867e>:0
  at TS3AudioBot.CommandSystem.RootCommand.Execute (TS3AudioBot.CommandSystem.ExecutionInformation info, System.Collections.Generic.IEnumerable`1[T] arguments, System.Collections.Generic.IEnumerable`1[T] returnTypes) [0x00062] in <bbaf56f358a145f5912928023124867e>:0
  at TS3AudioBot.CommandSystem.AppliedCommand.Execute (TS3AudioBot.CommandSystem.ExecutionInformation info, System.Collections.Generic.IEnumerable`1[T] arguments, System.Collections.Generic.IEnumerable`1[T] returnTypes) [0x00013] in <bbaf56f358a145f5912928023124867e>:0
  at TS3AudioBot.MainBot.TextCallback (System.Object sender, TS3Client.Messages.TextMessage textMessage) [0x001f5] in <bbaf56f358a145f5912928023124867e>:0

Error call Stack:
Void TextCallback(System.Object, TS3Client.Messages.TextMessage)@0
Void ExtendedTextMessage(System.Object, System.Collections.Generic.IEnumerable`1[TS3Client.Messages.TextMessage])@0
Void InvokeEvent(TS3Client.LazyNotification)@0
Void DispatchLoop()@0
Void ThreadStart_Context(System.Object)@0
Void RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)@0
Void Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)@0
Void Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)@0
Void ThreadStart()@0 T:TS3Query MessageLoop

[Splamy]

Hmm, the cast crash is unrelated to the thing i fixed. This happens because the database we use is buggy. If you dont care about the played songs database you can delete the histoty.db and try again.
I'm really thinking about switching the db system to another library since I really hear about this error a lot lately.

[robotrono]

@Splamy I see, then "playlists" dont work right?

[Splamy]

playlist should work fine, the history database just might be corrupted and when the playlist contains a song which is in the history - boom. As said when you never use !history just delete the history.db file and it should work fine again

[robotrono]

@Splamy thanks so much for the fix, the bot has not been disconnected for 5 days!

[Splamy]

Thats really nice to hear. I'll close this issue then.