Paste #15577: Denizen Debug Logs From A Test Server

Date: 2015/05/05 15:50:55 UTC-07:00
Type: Server Log

View Raw Paste Download This Paste
Copy Link


Java Version: 1.7.0_51
Up-time: 4m 7s
CraftBukkit Version: git-Spigot-2ec6f06-7722428 (MC: 1.8.3)
Denizen Version: Core: 1.05 (Build Unknown), CraftBukkit: 0.9.6-SNAPSHOT (build 1574)
Active Plugins (13): Citizens: 2.0.15-SNAPSHOT (build 1228), AsyncWorldEditInjector: 2.1.3, WorldEdit: 6.0.2-SNAPSHOT;3370-58aac973, 
Denizen: 0.9.6-SNAPSHOT (build 1574), Prism: 2.0.6-35, WorldGuard: 6.0.0-SNAPSHOT.1592-, 
RemoteToolkitPlugin: R10_A15.3, Essentials: TeamCity, Depenizen: 0.2.1 (build 245), 
WorldEditSelectionVisualizer: 1.4.2, Webizen: ${project.version} (build ${BUILD_NUMBER}), 
EssentialsChat: TeamCity, AsyncWorldEdit: 2.1.5
Loaded Worlds (7): world, world_nether, world_the_end, lotr, LOTR MAP, world1, doesntreallymatter
Online Players (1): TheBlackCoyote(TheBlackCoyote)
Offline Players: 8
Mode: online

18:50:51 [INFO] +> Executing 'Event': Type='on player breaks block'  
                   Container='SQL_MANAGING(WORLD)'  
                   player=p@TheBlackCoyoteContext='{cuboids=li@, 
                   location=l@-390.0,8.0,74.0,world, xp=0, material=m@stone}' 
18:50:51 [INFO] +- Building event 'ON PLAYER BREAKS BLOCK' for SQL_MANAGING 
                   ---------+ 
18:50:51 [INFO]  Starting InstantQueue 'SQL_MANAGING_SoIncentivesIntegrate'... 
18:50:51 [INFO]  Queue 'SQL_MANAGING_SoIncentivesIntegrate' Executing: WAIT 
                   "1t" 
18:50:51 [INFO] +- Executing dCommand: WAIT/p@TheBlackCoyote ---------+ 
18:50:51 [INFO] +> Executing 'WAIT': 
                   queue='SQL_MANAGING_SoIncentivesIntegrate'  delay='d@1t' 
18:50:51 [INFO]  Forcing queue SQL_MANAGING_SoIncentivesIntegrate into a timed 
                   queue... 
18:50:51 [INFO]  Completing queue 'SQL_MANAGING_SoIncentivesIntegrate' in 
                   35ms. 
18:50:51 [INFO]  Starting TimedQueue 'SQL_MANAGING_SoIncentivesIntegrate'... 
18:50:51 [INFO] +> Executing 'Event': Type='on player breaks stone'  
                   Container='EXPERIENCE_GAINS_MINING(WORLD)'  
                   player=p@TheBlackCoyoteContext='{cuboids=li@, 
                   location=l@-390.0,8.0,74.0,world, xp=0, material=m@stone}' 
18:50:51 [INFO] +- Building event 'ON PLAYER BREAKS STONE' for 
                   EXPERIENCE_GAINS_MINING ---------+ 
18:50:51 [INFO]  Starting InstantQueue 
                   'EXPERIENCE_GAINS_MINING_BandInvestorFireplace'... 
18:50:51 [INFO]  Queue 'EXPERIENCE_GAINS_MINING_BandInvestorFireplace' 
                   Executing: IF "<context.location.prism_logs.as_string||none>" 
                   "contains" "player" "define" "effect" "reduce" 
18:50:51 [INFO] +- Executing dCommand: IF/p@TheBlackCoyote ---------+ 
18:50:51 [INFO] +> Executing 'IF': use_braces='false' 
18:50:51 [INFO]  Filled tag <context.location.prism_logs.as_string||none> with 
                   ''. 
18:50:51 [INFO]  Comparable='Element()', Operator='CONTAINS', 
                   ComparedTo='Element(player)' --> OUTCOME='false' 
18:50:51 [INFO]  Queue 'EXPERIENCE_GAINS_MINING_BandInvestorFireplace' 
                   Executing: WAIT "1t" 
18:50:51 [INFO] +- Executing dCommand: WAIT/p@TheBlackCoyote ---------+ 
18:50:51 [INFO] +> Executing 'WAIT': 
                   queue='EXPERIENCE_GAINS_MINING_BandInvestorFireplace'  
                   delay='d@1t' 
18:50:51 [INFO]  Forcing queue EXPERIENCE_GAINS_MINING_BandInvestorFireplace 
                   into a timed queue... 
18:50:51 [INFO]  Completing queue 
                   'EXPERIENCE_GAINS_MINING_BandInvestorFireplace' in 18ms. 
18:50:51 [INFO]  Starting TimedQueue 
                   'EXPERIENCE_GAINS_MINING_BandInvestorFireplace'... 
18:50:51 [INFO]  Queue 'SQL_MANAGING_SoIncentivesIntegrate' Executing: SQL 
                   "id:DE" "update:INSERT INTO block_tracking(location,cause) 
                   VALUES (<context.location.simple>,player);" 
18:50:51 [INFO] +- Executing dCommand: SQL/p@TheBlackCoyote ---------+ 
18:50:51 [INFO]  Filled tag <context.location.simple> with '-390,8,74,world'. 
18:50:51 [INFO] +> Executing 'SQL': sqlid='DE'  action='UPDATE'  query='INSERT 
                   INTO block_tracking(location,cause) VALUES 
                   (-390,8,74,world,player);' 
18:50:51 [INFO]  Running update INSERT INTO block_tracking(location,cause) 
                   VALUES (-390,8,74,world,player); 
18:50:51 [INFO]  ERROR in script 'SQL_MANAGING'! SQL Exception: Table 
                   'denizens.block_tracking' doesn't exist 
18:50:51 [INFO]  Queue 'SQL_MANAGING_SoIncentivesIntegrate' Executing: WAIT 
                   "2s" 
18:50:51 [INFO] +- Executing dCommand: WAIT/p@TheBlackCoyote ---------+ 
18:50:51 [INFO] +> Executing 'WAIT': 
                   queue='SQL_MANAGING_SoIncentivesIntegrate'  delay='d@40t' 
18:50:51 [INFO]  Queue 'EXPERIENCE_GAINS_MINING_BandInvestorFireplace' 
                   Executing: RUN "give_exp" "def:mining|10|<def[effect]||none>" 
                   "instantly" 
18:50:51 [INFO] +- Executing dCommand: RUN/p@TheBlackCoyote ---------+ 
18:50:51 [INFO]  Filled tag <def[effect]||none> with 'none'. 
18:50:51 [INFO] +> Executing 'RUN': script='GIVE_EXP(TASK)'  instant='true'  
                   definitions='li@mining|10|none' 
18:50:51 [INFO]  Adding definition %1% as mining 
18:50:51 [INFO]  Adding definition %2% as 10 
18:50:51 [INFO]  Adding definition %3% as none 
18:50:51 [INFO]  Starting InstantQueue 'GIVE_EXP_HencePathsAttorney'... 
18:50:51 [INFO]  Queue 'GIVE_EXP_HencePathsAttorney' Executing: IF "<def[3]>" 
                   "==" "reduce" "{" "-" "define" "2" 
                   "<def[2].div[100].round_up>" "}" 
18:50:51 [INFO] +- Executing dCommand: IF/p@TheBlackCoyote ---------+ 
18:50:51 [INFO] +> Executing 'IF': use_braces='true' 
18:50:51 [INFO]  Filled tag <def[3]> with 'none'. 
18:50:51 [INFO]  Comparable='Element(none)', Operator='EQUALS', 
                   ComparedTo='Element(reduce)' --> OUTCOME='false' 
18:50:51 [INFO]  Queue 'GIVE_EXP_HencePathsAttorney' Executing: FLAG 
                   "<player>" "<def[1]>_exp:+:<def[2]>" 
18:50:51 [INFO] +- Executing dCommand: FLAG/p@TheBlackCoyote ---------+ 
18:50:51 [INFO]  Filled tag <player> with 
                   'p@4c570928-3648-4583-9148-ee5ca157e175'. 
18:50:51 [INFO]  Filled tag <def[1]> with 'mining'. 
18:50:51 [INFO]  Filled tag <def[2]> with '10'. 
18:50:51 [INFO] +> Executing 'FLAG': flag_name='MINING_EXP'  
                   Action/Value='INCREASE(10)'  flag_target='p@TheBlackCoyote' 
18:50:51 [INFO]  Queue 'GIVE_EXP_HencePathsAttorney' Executing: TITLE 
                   "subtitle:<&f>                            
                   <&7>+<player.flag[exp_drop].add[<def[2]>].as_int||<def[2]>> 
                   xp" "targets:<player>" "fade_in:1t" "stay:10t" "fade_out:2s" 
18:50:51 [INFO] +- Executing dCommand: TITLE/p@TheBlackCoyote ---------+ 
18:50:51 [INFO]  Filled tag <&f> with ''. 
18:50:51 [INFO]  Filled tag <&7> with ''. 
18:50:51 [INFO]  Filled tag <def[2]> with '10'. 
18:50:51 [INFO]  Filled tag <player.flag[exp_drop].add[<def[2]>].as_int||10> 
                   with '10'. 
18:50:51 [INFO]  Filled tag <player> with 
                   'p@4c570928-3648-4583-9148-ee5ca157e175'. 
18:50:51 [INFO] +> Executing 'TITLE': subtitle='                            
                   +10 xp'  fade_in='d@1t'  stay='d@10t'  fade_out='d@40t'  
                   targets='[p@4c570928-3648-4583-9148-ee5ca157e175]' 
18:50:51 [INFO]  Queue 'GIVE_EXP_HencePathsAttorney' Executing: FLAG 
                   "<player>" "exp_drop:+:<def[2]>" "duration:2s" 
18:50:51 [INFO] +- Executing dCommand: FLAG/p@TheBlackCoyote ---------+ 
18:50:51 [INFO]  Filled tag <player> with 
                   'p@4c570928-3648-4583-9148-ee5ca157e175'. 
18:50:51 [INFO]  Filled tag <def[2]> with '10'. 
18:50:51 [INFO] +> Executing 'FLAG': flag_name='EXP_DROP'  
                   Action/Value='INCREASE(10)'  duration='d@40t'  
                   flag_target='p@TheBlackCoyote' 
18:50:51 [INFO]  Queue 'GIVE_EXP_HencePathsAttorney' Executing: RUN 
                   "check_level" "def:<def[1]>" "instantly" 
18:50:51 [INFO] +- Executing dCommand: RUN/p@TheBlackCoyote ---------+ 
18:50:51 [INFO]  Filled tag <def[1]> with 'mining'. 
18:50:51 [INFO] +> Executing 'RUN': script='CHECK_LEVEL(TASK)'  instant='true' 
                    definitions='li@mining' 
18:50:51 [INFO]  Adding definition %1% as mining 
18:50:51 [INFO]  Starting InstantQueue 
                   'CHECK_LEVEL_TerminologyPracticesFraming'... 
18:50:51 [INFO]  Queue 'CHECK_LEVEL_TerminologyPracticesFraming' Executing: IF 
                   "<player.flag[<def[1]>_exp]>" ">=" 
                   "<player.flag[<def[1]>_level].power[2.6].mul[84]||1>" "run" 
                   "level_up" "def:<def[1]>" "instantly" 
18:50:51 [INFO] +- Executing dCommand: IF/p@TheBlackCoyote ---------+ 
18:50:51 [INFO] +> Executing 'IF': use_braces='false' 
18:50:51 [INFO]  Filled tag <def[1]> with 'mining'. 
18:50:51 [INFO]  Filled tag <player.flag[mining_exp]> with '347627.0'. 
18:50:51 [INFO]  Filled tag <def[1]> with 'mining'. 
18:50:51 [INFO]  Filled tag <player.flag[mining_level].power[2.6].mul[84]||1> 
                   with '362179.036133569032'. 
18:50:51 [INFO]  Comparable='Decimal(347627.0)', Operator='OR_MORE', 
                   ComparedTo='Decimal(362179.036133569)' --> OUTCOME='false' 
18:50:51 [INFO]  Completing queue 'CHECK_LEVEL_TerminologyPracticesFraming' in 
                   11ms. 
18:50:51 [INFO]  Queue 'GIVE_EXP_HencePathsAttorney' Executing: RUN 
                   "show_exp_boss_bar" "def:<def[1]>" 
18:50:51 [INFO] +- Executing dCommand: RUN/p@TheBlackCoyote ---------+ 
18:50:51 [INFO]  Filled tag <def[1]> with 'mining'. 
18:50:51 [INFO] +> Executing 'RUN': script='SHOW_EXP_BOSS_BAR(TASK)'  
                   definitions='li@mining' 
18:50:51 [INFO]  Adding definition %1% as mining 
18:50:51 [INFO]  Starting TimedQueue 'SHOW_EXP_BOSS_BAR_DenizenBath'... 
18:50:51 [INFO]  Queue 'SHOW_EXP_BOSS_BAR_DenizenBath' Executing: FLAG 
                   "<player>" "show_boss_bar:true" "duration:5s" 
18:50:51 [INFO] +- Executing dCommand: FLAG/p@TheBlackCoyote ---------+ 
18:50:51 [INFO]  Filled tag <player> with 
                   'p@4c570928-3648-4583-9148-ee5ca157e175'. 
18:50:51 [INFO] +> Executing 'FLAG': flag_name='SHOW_BOSS_BAR'  
                   Action/Value='SET_VALUE(true)'  duration='d@100t'  
                   flag_target='p@TheBlackCoyote' 
18:50:51 [INFO]  Completing queue 'GIVE_EXP_HencePathsAttorney' in 66ms. 
18:50:51 [INFO]  Completing queue 
                   'EXPERIENCE_GAINS_MINING_BandInvestorFireplace' in 150ms. 
18:50:51 [INFO]  ERROR in script 'ABILITY_COOLDOWN_VISUALIZER'! Scoreboard 
                   TheBlackCoyote1430866249648 does not exist! 
18:50:52 [INFO]  Queue 'SHOW_EXP_BOSS_BAR_DenizenBath' Executing: ADJUST 
                   "<player>" 
                   "show_boss_bar:<player.flag[<def[1]>_exp].sub[<player.flag[<def[1]>_level].sub[1].power[2.6].mul[84]||1>].div[<player.flag[<def[1]>_level].power[2.6].mul[84].sub[<player.flag[<def[1]>_level].sub[1].power[2.6].mul[84]||1>]||1>].mul[200].as_int>|<&d><player.flag[<def[1]>_level].as_int||0> 
                            <def[1]> progress          
                   <player.flag[<def[1]>_level].add[1].as_int||0>" 
18:50:52 [INFO] +- Executing dCommand: ADJUST/p@TheBlackCoyote ---------+ 
18:50:52 [INFO]  Filled tag <player> with 
                   'p@4c570928-3648-4583-9148-ee5ca157e175'. 
18:50:52 [INFO]  Filled tag <def[1]> with 'mining'. 
18:50:52 [INFO]  Filled tag <def[1]> with 'mining'. 
18:50:52 [INFO]  Filled tag 
                   <player.flag[mining_level].sub[1].power[2.6].mul[84]||1> with 
                   '325708.0665436135692'. 
18:50:52 [INFO]  Filled tag <def[1]> with 'mining'. 
18:50:52 [INFO]  Filled tag <def[1]> with 'mining'. 
18:50:52 [INFO]  Filled tag 
                   <player.flag[mining_level].sub[1].power[2.6].mul[84]||1> with 
                   '325708.0665436135692'. 
18:50:52 [INFO]  Filled tag 
                   <player.flag[mining_level].power[2.6].mul[84].sub[325708.0665436135692]||1> 
                   with '36470.9695899554628'. 
18:50:52 [INFO]  Filled tag 
                   <player.flag[mining_exp].sub[325708.0665436135692].div[36470.9695899554628].mul[200].as_int> 
                   with '120'. 
18:50:52 [INFO]  Filled tag <&d> with ''. 
18:50:52 [INFO]  Filled tag <def[1]> with 'mining'. 
18:50:52 [INFO]  Filled tag <player.flag[mining_level].as_int||0> with '25'. 
18:50:52 [INFO]  Filled tag <def[1]> with 'mining'. 
18:50:52 [INFO]  Filled tag <def[1]> with 'mining'. 
18:50:52 [INFO]  Filled tag <player.flag[mining_level].add[1].as_int||0> with 
                   '26'. 
18:50:52 [INFO] +> Executing 'ADJUST': 
                   object='p@4c570928-3648-4583-9148-ee5ca157e175'  
                   mechanism='show_boss_bar'  mechanism_value='120|25          
                   mining progress          26' 
18:50:52 [INFO]  Queue 'SHOW_EXP_BOSS_BAR_DenizenBath' Executing: ADJUST 
                   "<player>" 
                   "tab_list_info:<&nl><&d><player.flag[<def[1]>_exp].as_int>    
                   -    XP remaining<&co> 
                   <player.flag[<def[1]>_level].power[2.6].mul[84].sub[<player.flag[<def[1]>_exp]>].round_up> 
                      -    
                   <player.flag[<def[1]>_level].power[2.6].mul[84].as_int><&nl><&b>" 
18:50:52 [INFO] +- Executing dCommand: ADJUST/p@TheBlackCoyote ---------+ 
18:50:52 [INFO]  Filled tag <player> with 
                   'p@4c570928-3648-4583-9148-ee5ca157e175'. 
18:50:52 [INFO]  Filled tag <&nl> with '
'. 
18:50:52 [INFO]  Filled tag <&d> with ''. 
18:50:52 [INFO]  Filled tag <def[1]> with 'mining'. 
18:50:52 [INFO]  Filled tag <player.flag[mining_exp].as_int> with '347627'. 
18:50:52 [INFO]  Filled tag <&co> with ':'. 
18:50:52 [INFO]  Filled tag <def[1]> with 'mining'. 
18:50:52 [INFO]  Filled tag <def[1]> with 'mining'. 
18:50:52 [INFO]  Filled tag <player.flag[mining_exp]> with '347627.0'. 
18:50:52 [INFO]  Filled tag 
                   <player.flag[mining_level].power[2.6].mul[84].sub[347627.0].round_up> 
                   with '14553'. 
18:50:52 [INFO]  Filled tag <def[1]> with 'mining'. 
18:50:52 [INFO]  Filled tag 
                   <player.flag[mining_level].power[2.6].mul[84].as_int> with 
                   '362179'. 
18:50:52 [INFO]  Filled tag <&nl> with '
'. 
18:50:52 [INFO]  Filled tag <&b> with ''. 
18:50:52 [INFO] +> Executing 'ADJUST': 
                   object='p@4c570928-3648-4583-9148-ee5ca157e175'  
                   mechanism='tab_list_info'  mechanism_value='
347627    -    XP 
                   remaining: 14553    -    362179
' 
18:50:53 [INFO]  Queue 'SHOW_EXP_BOSS_BAR_DenizenBath' Executing: WAIT "6s" 
18:50:53 [INFO] +- Executing dCommand: WAIT/p@TheBlackCoyote ---------+ 
18:50:53 [INFO] +> Executing 'WAIT': queue='SHOW_EXP_BOSS_BAR_DenizenBath'  
                   delay='d@120t' 
18:50:53 [INFO]  Queue 'SQL_MANAGING_SoIncentivesIntegrate' Executing: SQL 
                   "id:DE" "querry:SELECT * FROM block_tracking WHERE 
                   location='<context.location.simple>';" "save:return" 
18:50:53 [INFO] +- Executing dCommand: SQL/p@TheBlackCoyote ---------+ 
18:50:53 [INFO]  ...remembering this script entry as 'return'! 
18:50:53 [INFO]  Filled tag <context.location.simple> with '-390,8,74,world'. 
18:50:53 [INFO]  ERROR! 'querry:SELECT * FROM block_tracking WHERE 
                   location='-390,8,74,world';' is an unknown argument! 
18:50:53 [INFO]  ERROR in script 'SQL_MANAGING'! Woah! Invalid arguments were 
                   specified! 
18:50:53 [INFO] +> [Denizen] +> MESSAGE follows: 'Must specify an action!' 
18:50:53 [INFO] +> [Denizen] Usage: sql [id:<ID>] 
                   [disconnect/connect:<server>/query:<query>/update:<update>] 
                   (username:<username>) (password:<password>) 
18:50:53 [INFO] +> [Denizen] (Attempted: SQL "id:DE" "querry:SELECT * FROM 
                   block_tracking WHERE location='<context.location.simple>';" 
                   "save:return") 
18:50:53 [INFO] +---------------------+ 
18:50:53 [INFO]  Queue 'SQL_MANAGING_SoIncentivesIntegrate' Executing: NARRATE 
                   "<entry[return].result>" 
18:50:53 [INFO] +- Executing dCommand: NARRATE/p@TheBlackCoyote ---------+ 
18:50:53 [INFO]  Missing saved entry object 'result' 
18:50:53 [INFO]  Filled tag <entry[return].result> with 
                   'entry[return].result'. 
18:50:53 [INFO]  ERROR in script 'SQL_MANAGING'! Tag <entry[return].result> is 
                   invalid! 
18:50:53 [INFO] +> Executing 'NARRATE': Narrating='entry[return].result'  
                   Targets='[p@TheBlackCoyote]' 
18:50:53 [INFO]  Completing queue 'SQL_MANAGING_SoIncentivesIntegrate' in 
                   2206ms. 
18:50:53 [INFO]  ERROR in script 'ABILITY_COOLDOWN_VISUALIZER'! Scoreboard 
                   TheBlackCoyote1430866251813 does not exist!