I found out (after printing more debug messages) that the contract code length that has been called in this case was 0. So, the VM returned immediately, this is why I didn't see a depth increase after CALL.
But a CALL
always increases depth, is an exmaple log for block 78458:
INFO [04-05|21:06:55] i=0,OPCODE=PUSH1,GAS=179000,GAS COST=3,depth=1 PC=0 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=1,OPCODE=PUSH1,GAS=178997,GAS COST=3,depth=1 PC=2 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=2,OPCODE=MSTORE,GAS=178994,GAS COST=12,depth=1 PC=4 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=3,OPCODE=CALLDATASIZE,GAS=178982,GAS COST=2,depth=1 PC=5 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=4,OPCODE=ISZERO,GAS=178980,GAS COST=3,depth=1 PC=6 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=5,OPCODE=PUSH2,GAS=178977,GAS COST=3,depth=1 PC=7 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=6,OPCODE=JUMPI,GAS=178974,GAS COST=10,depth=1 PC=10 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=7,OPCODE=JUMPDEST,GAS=178964,GAS COST=1,depth=1 PC=61 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=8,OPCODE=PUSH2,GAS=178963,GAS COST=3,depth=1 PC=62 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=9,OPCODE=JUMPDEST,GAS=178960,GAS COST=1,depth=1 PC=65 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=10,OPCODE=PUSH3,GAS=178959,GAS COST=3,depth=1 PC=66 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=11,OPCODE=NUMBER,GAS=178956,GAS COST=2,depth=1 PC=70 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=12,OPCODE=GT,GAS=178954,GAS COST=3,depth=1 PC=71 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=13,OPCODE=ISZERO,GAS=178951,GAS COST=3,depth=1 PC=72 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=14,OPCODE=PUSH2,GAS=178948,GAS COST=3,depth=1 PC=73 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=15,OPCODE=JUMPI,GAS=178945,GAS COST=10,depth=1 PC=76 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=16,OPCODE=JUMPDEST,GAS=178935,GAS COST=1,depth=1 PC=171 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=17,OPCODE=PUSH3,GAS=178934,GAS COST=3,depth=1 PC=172 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=18,OPCODE=NUMBER,GAS=178931,GAS COST=2,depth=1 PC=176 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=19,OPCODE=LT,GAS=178929,GAS COST=3,depth=1 PC=177 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=20,OPCODE=DUP1,GAS=178926,GAS COST=3,depth=1 PC=178 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=21,OPCODE=ISZERO,GAS=178923,GAS COST=3,depth=1 PC=179 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=22,OPCODE=PUSH2,GAS=178920,GAS COST=3,depth=1 PC=180 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=23,OPCODE=JUMPI,GAS=178917,GAS COST=10,depth=1 PC=183 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=24,OPCODE=POP,GAS=178907,GAS COST=2,depth=1 PC=184 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=25,OPCODE=NUMBER,GAS=178905,GAS COST=2,depth=1 PC=185 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=26,OPCODE=PUSH2,GAS=178903,GAS COST=3,depth=1 PC=186 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=27,OPCODE=PUSH1,GAS=178900,GAS COST=3,depth=1 PC=189 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=28,OPCODE=PUSH1,GAS=178897,GAS COST=3,depth=1 PC=191 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=29,OPCODE=SWAP1,GAS=178894,GAS COST=3,depth=1 PC=193 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=30,OPCODE=SLOAD,GAS=178891,GAS COST=50,depth=1 PC=194 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=31,OPCODE=SWAP1,GAS=178841,GAS COST=3,depth=1 PC=195 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=32,OPCODE=PUSH2,GAS=178838,GAS COST=3,depth=1 PC=196 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=33,OPCODE=EXP,GAS=178835,GAS COST=10,depth=1 PC=199 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=34,OPCODE=SWAP1,GAS=178825,GAS COST=3,depth=1 PC=200 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=35,OPCODE=DIV,GAS=178822,GAS COST=5,depth=1 PC=201 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=36,OPCODE=PUSH8,GAS=178817,GAS COST=3,depth=1 PC=202 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=37,OPCODE=AND,GAS=178814,GAS COST=3,depth=1 PC=211 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=38,OPCODE=ADD,GAS=178811,GAS COST=3,depth=1 PC=212 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=39,OPCODE=PUSH8,GAS=178808,GAS COST=3,depth=1 PC=213 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=40,OPCODE=AND,GAS=178805,GAS COST=3,depth=1 PC=222 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=41,OPCODE=LT,GAS=178802,GAS COST=3,depth=1 PC=223 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=42,OPCODE=JUMPDEST,GAS=178799,GAS COST=1,depth=1 PC=224 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=43,OPCODE=DUP1,GAS=178798,GAS COST=3,depth=1 PC=225 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=44,OPCODE=ISZERO,GAS=178795,GAS COST=3,depth=1 PC=226 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=45,OPCODE=PUSH2,GAS=178792,GAS COST=3,depth=1 PC=227 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=46,OPCODE=JUMPI,GAS=178789,GAS COST=10,depth=1 PC=230 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=47,OPCODE=POP,GAS=178779,GAS COST=2,depth=1 PC=231 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=48,OPCODE=PUSH8,GAS=178777,GAS COST=3,depth=1 PC=232 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=49,OPCODE=ADDRESS,GAS=178774,GAS COST=2,depth=1 PC=241 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=50,OPCODE=PUSH20,GAS=178772,GAS COST=3,depth=1 PC=242 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=51,OPCODE=AND,GAS=178769,GAS COST=3,depth=1 PC=263 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=52,OPCODE=BALANCE,GAS=178766,GAS COST=20,depth=1 PC=264 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=53,OPCODE=LT,GAS=178746,GAS COST=3,depth=1 PC=265 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=54,OPCODE=ISZERO,GAS=178743,GAS COST=3,depth=1 PC=266 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=55,OPCODE=JUMPDEST,GAS=178740,GAS COST=1,depth=1 PC=267 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=56,OPCODE=ISZERO,GAS=178739,GAS COST=3,depth=1 PC=268 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=57,OPCODE=PUSH2,GAS=178736,GAS COST=3,depth=1 PC=269 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=58,OPCODE=JUMPI,GAS=178733,GAS COST=10,depth=1 PC=272 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=59,OPCODE=NUMBER,GAS=178723,GAS COST=2,depth=1 PC=273 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=60,OPCODE=PUSH1,GAS=178721,GAS COST=3,depth=1 PC=274 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=61,OPCODE=PUSH1,GAS=178718,GAS COST=3,depth=1 PC=276 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=62,OPCODE=PUSH2,GAS=178715,GAS COST=3,depth=1 PC=278 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=63,OPCODE=EXP,GAS=178712,GAS COST=10,depth=1 PC=281 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=64,OPCODE=DUP2,GAS=178702,GAS COST=3,depth=1 PC=282 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=65,OPCODE=SLOAD,GAS=178699,GAS COST=50,depth=1 PC=283 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=66,OPCODE=DUP2,GAS=178649,GAS COST=3,depth=1 PC=284 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=67,OPCODE=PUSH8,GAS=178646,GAS COST=3,depth=1 PC=285 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=68,OPCODE=MUL,GAS=178643,GAS COST=5,depth=1 PC=294 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=69,OPCODE=NOT,GAS=178638,GAS COST=3,depth=1 PC=295 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=70,OPCODE=AND,GAS=178635,GAS COST=3,depth=1 PC=296 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=71,OPCODE=SWAP1,GAS=178632,GAS COST=3,depth=1 PC=297 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=72,OPCODE=DUP4,GAS=178629,GAS COST=3,depth=1 PC=298 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=73,OPCODE=MUL,GAS=178626,GAS COST=5,depth=1 PC=299 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=74,OPCODE=OR,GAS=178621,GAS COST=3,depth=1 PC=300 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=75,OPCODE=SWAP1,GAS=178618,GAS COST=3,depth=1 PC=301 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=76,OPCODE=SSTORE,GAS=178615,GAS COST=20000,depth=1 PC=302 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=77,OPCODE=POP,GAS=158615,GAS COST=2,depth=1 PC=303 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=78,OPCODE=PUSH20,GAS=158613,GAS COST=3,depth=1 PC=304 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=79,OPCODE=PUSH20,GAS=158610,GAS COST=3,depth=1 PC=325 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=80,OPCODE=AND,GAS=158607,GAS COST=3,depth=1 PC=346 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=81,OPCODE=PUSH1,GAS=158604,GAS COST=3,depth=1 PC=347 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=82,OPCODE=PUSH8,GAS=158601,GAS COST=3,depth=1 PC=349 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=83,OPCODE=PUSH1,GAS=158598,GAS COST=3,depth=1 PC=358 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=84,OPCODE=MLOAD,GAS=158595,GAS COST=3,depth=1 PC=360 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=85,OPCODE=DUP1,GAS=158592,GAS COST=3,depth=1 PC=361 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=86,OPCODE=SWAP1,GAS=158589,GAS COST=3,depth=1 PC=362 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=87,OPCODE=POP,GAS=158586,GAS COST=2,depth=1 PC=363 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=88,OPCODE=PUSH1,GAS=158584,GAS COST=3,depth=1 PC=364 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=89,OPCODE=PUSH1,GAS=158581,GAS COST=3,depth=1 PC=366 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=90,OPCODE=MLOAD,GAS=158578,GAS COST=3,depth=1 PC=368 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=91,OPCODE=DUP1,GAS=158575,GAS COST=3,depth=1 PC=369 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=92,OPCODE=DUP4,GAS=158572,GAS COST=3,depth=1 PC=370 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=93,OPCODE=SUB,GAS=158569,GAS COST=3,depth=1 PC=371 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=94,OPCODE=DUP2,GAS=158566,GAS COST=3,depth=1 PC=372 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=95,OPCODE=DUP6,GAS=158563,GAS COST=3,depth=1 PC=373 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=96,OPCODE=DUP9,GAS=158560,GAS COST=3,depth=1 PC=374 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=97,OPCODE=DUP9,GAS=158557,GAS COST=3,depth=1 PC=375 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=98,OPCODE=CALL,GAS=158554,GAS COST=9040,depth=1 PC=376 stacklen=1 err=<nil> eberr=out of gas
INFO [04-05|21:06:55] i=99,OPCODE=PUSH1,GAS=2300,GAS COST=3,depth=2 PC=0 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=100,OPCODE=PUSH1,GAS=2297,GAS COST=3,depth=2 PC=2 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=101,OPCODE=MSTORE,GAS=2294,GAS COST=12,depth=2 PC=4 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=102,OPCODE=CALLDATASIZE,GAS=2282,GAS COST=2,depth=2 PC=5 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=103,OPCODE=ISZERO,GAS=2280,GAS COST=3,depth=2 PC=6 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=104,OPCODE=PUSH2,GAS=2277,GAS COST=3,depth=2 PC=7 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=105,OPCODE=JUMPI,GAS=2274,GAS COST=10,depth=2 PC=10 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=106,OPCODE=JUMPDEST,GAS=2264,GAS COST=1,depth=2 PC=170 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=107,OPCODE=PUSH2,GAS=2263,GAS COST=3,depth=2 PC=171 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=108,OPCODE=JUMPDEST,GAS=2260,GAS COST=1,depth=2 PC=174 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=109,OPCODE=PUSH2,GAS=2259,GAS COST=3,depth=2 PC=175 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=110,OPCODE=PUSH1,GAS=2256,GAS COST=3,depth=2 PC=178 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=111,OPCODE=PUSH2,GAS=2253,GAS COST=3,depth=2 PC=180 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=112,OPCODE=JUMP,GAS=2250,GAS COST=8,depth=2 PC=183 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=113,OPCODE=JUMPDEST,GAS=2242,GAS COST=1,depth=2 PC=620 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=114,OPCODE=PUSH1,GAS=2241,GAS COST=3,depth=2 PC=621 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=115,OPCODE=CALLVALUE,GAS=2238,GAS COST=2,depth=2 PC=623 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=116,OPCODE=SWAP1,GAS=2236,GAS COST=3,depth=2 PC=624 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=117,OPCODE=POP,GAS=2233,GAS COST=2,depth=2 PC=625 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=118,OPCODE=NUMBER,GAS=2231,GAS COST=2,depth=2 PC=626 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=119,OPCODE=PUSH2,GAS=2229,GAS COST=3,depth=2 PC=627 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=120,OPCODE=PUSH1,GAS=2226,GAS COST=3,depth=2 PC=630 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=121,OPCODE=PUSH1,GAS=2223,GAS COST=3,depth=2 PC=632 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=122,OPCODE=SWAP1,GAS=2220,GAS COST=3,depth=2 PC=634 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=123,OPCODE=SLOAD,GAS=2217,GAS COST=50,depth=2 PC=635 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=124,OPCODE=SWAP1,GAS=2167,GAS COST=3,depth=2 PC=636 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=125,OPCODE=PUSH2,GAS=2164,GAS COST=3,depth=2 PC=637 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=126,OPCODE=EXP,GAS=2161,GAS COST=20,depth=2 PC=640 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=127,OPCODE=SWAP1,GAS=2141,GAS COST=3,depth=2 PC=641 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=128,OPCODE=DIV,GAS=2138,GAS COST=5,depth=2 PC=642 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=129,OPCODE=PUSH8,GAS=2133,GAS COST=3,depth=2 PC=643 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=130,OPCODE=AND,GAS=2130,GAS COST=3,depth=2 PC=652 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=131,OPCODE=ADD,GAS=2127,GAS COST=3,depth=2 PC=653 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=132,OPCODE=PUSH8,GAS=2124,GAS COST=3,depth=2 PC=654 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=133,OPCODE=AND,GAS=2121,GAS COST=3,depth=2 PC=663 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=134,OPCODE=LT,GAS=2118,GAS COST=3,depth=2 PC=664 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=135,OPCODE=ISZERO,GAS=2115,GAS COST=3,depth=2 PC=665 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=136,OPCODE=PUSH2,GAS=2112,GAS COST=3,depth=2 PC=666 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=137,OPCODE=JUMPI,GAS=2109,GAS COST=10,depth=2 PC=669 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=138,OPCODE=JUMPDEST,GAS=2099,GAS COST=1,depth=2 PC=828 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=139,OPCODE=PUSH1,GAS=2098,GAS COST=3,depth=2 PC=829 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=140,OPCODE=DUP2,GAS=2095,GAS COST=3,depth=2 PC=831 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=141,OPCODE=ADDRESS,GAS=2092,GAS COST=2,depth=2 PC=832 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=142,OPCODE=PUSH20,GAS=2090,GAS COST=3,depth=2 PC=833 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=143,OPCODE=AND,GAS=2087,GAS COST=3,depth=2 PC=854 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=144,OPCODE=BALANCE,GAS=2084,GAS COST=20,depth=2 PC=855 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=145,OPCODE=SUB,GAS=2064,GAS COST=3,depth=2 PC=856 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=146,OPCODE=DIV,GAS=2061,GAS COST=5,depth=2 PC=857 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=147,OPCODE=DUP2,GAS=2056,GAS COST=3,depth=2 PC=858 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=148,OPCODE=LT,GAS=2053,GAS COST=3,depth=2 PC=859 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=149,OPCODE=ISZERO,GAS=2050,GAS COST=3,depth=2 PC=860 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=150,OPCODE=ISZERO,GAS=2047,GAS COST=3,depth=2 PC=861 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=151,OPCODE=PUSH2,GAS=2044,GAS COST=3,depth=2 PC=862 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=152,OPCODE=JUMPI,GAS=2041,GAS COST=10,depth=2 PC=865 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=153,OPCODE=NUMBER,GAS=2031,GAS COST=2,depth=2 PC=866 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=154,OPCODE=PUSH1,GAS=2029,GAS COST=3,depth=2 PC=867 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=155,OPCODE=PUSH1,GAS=2026,GAS COST=3,depth=2 PC=869 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=156,OPCODE=PUSH2,GAS=2023,GAS COST=3,depth=2 PC=871 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=157,OPCODE=EXP,GAS=2020,GAS COST=20,depth=2 PC=874 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=158,OPCODE=DUP2,GAS=2000,GAS COST=3,depth=2 PC=875 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=159,OPCODE=SLOAD,GAS=1997,GAS COST=50,depth=2 PC=876 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=160,OPCODE=DUP2,GAS=1947,GAS COST=3,depth=2 PC=877 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=161,OPCODE=PUSH8,GAS=1944,GAS COST=3,depth=2 PC=878 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=162,OPCODE=MUL,GAS=1941,GAS COST=5,depth=2 PC=887 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=163,OPCODE=NOT,GAS=1936,GAS COST=3,depth=2 PC=888 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=164,OPCODE=AND,GAS=1933,GAS COST=3,depth=2 PC=889 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=165,OPCODE=SWAP1,GAS=1930,GAS COST=3,depth=2 PC=890 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=166,OPCODE=DUP4,GAS=1927,GAS COST=3,depth=2 PC=891 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=167,OPCODE=MUL,GAS=1924,GAS COST=5,depth=2 PC=892 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=168,OPCODE=OR,GAS=1919,GAS COST=3,depth=2 PC=893 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=169,OPCODE=SWAP1,GAS=1916,GAS COST=3,depth=2 PC=894 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=170,OPCODE=SSTORE,GAS=1913,GAS COST=5000,depth=2 PC=895 stacklen=1 err=out of gas eberr=<nil>
INFO [04-05|21:06:55] i=171,OPCODE=SWAP4,GAS=149514,GAS COST=3,depth=1 PC=377 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=172,OPCODE=POP,GAS=149511,GAS COST=2,depth=1 PC=378 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=173,OPCODE=POP,GAS=149509,GAS COST=2,depth=1 PC=379 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=174,OPCODE=POP,GAS=149507,GAS COST=2,depth=1 PC=380 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=175,OPCODE=POP,GAS=149505,GAS COST=2,depth=1 PC=381 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=176,OPCODE=POP,GAS=149503,GAS COST=2,depth=1 PC=382 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=177,OPCODE=JUMPDEST,GAS=149501,GAS COST=1,depth=1 PC=383 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=178,OPCODE=JUMPDEST,GAS=149500,GAS COST=1,depth=1 PC=384 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=179,OPCODE=JUMP,GAS=149499,GAS COST=8,depth=1 PC=385 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=180,OPCODE=JUMPDEST,GAS=149491,GAS COST=1,depth=1 PC=386 stacklen=1 err=<nil> eberr=<nil>
INFO [04-05|21:06:55] i=181,OPCODE=STOP,GAS=149490,GAS COST=0,depth=1 PC=387 stacklen=1 err=<nil> eberr=<nil>
In this log you can see how each instruction decreases GAS and how each CALL creates a new GAS LIMIT of its own. And how the SUB-CALL doesn't abort the main CALL even if it gets "out of gas" error.
To find out what the VM is executing, add these lines before and after operation.execute
inside core/vm/interpreter.go
// execute the operation
log.Info(fmt.Sprintf("executing operation %v depth=%v, gas=%v",op,in.evm.depth,gasCopy))
res, err := operation.execute(&pc, in.evm, contract, mem, stack)
if (err!=nil) {
log.Info(fmt.Sprintf("returned error=%v",err))
}
CallValueTransferGas
. I am dumping the gas cost asCOST
variable in the log – Nulik Apr 3 '18 at 15:02