How to embed logging in a library?

[aathan]

Foundry is great because you don't have to context switch between Solidity and (for example) javascript when writing contracts. Sometimes, testing external to a contract is not enough. You want to get access to the state of variables inside a contract function as it's executing; and you want to do so outside a debugger. I.e., all you want to do is log some output.

So, my idea was to do something like this:

contract Tester is DSTest {
  using XLib for x;
  ...
  function _log_string(string memory s) public { emit log_string(s); }
  function testWhatever() public { emit log_address(x.whois()); foo(); }

interface ITester { function _log_string(string memory s) external; }

library XLib {
  function whois() internal returns(address){ return msg.sender; }
  function foo(X storage self) internal {
      ITest(address(0xb4c79daB8f259C7Aee6E5b2Aa729821864227e84))._log_string('success');
    }
}

This outputs:

[PASS] testWhatever() (gas: 4066)
Logs:
  0x00a329c0648769a73afac7f9381e08fb43dbea72
  success

Somewhat surprising, since the docs would imply msg.sender for calls from the test functions is 0xb4c79daB8f259C7Aee6E5b2Aa729821864227e84. So I thought maybe this is because it's an internal library function, and solidity is including the code into the test contract, therefor msg.sender is whoever is calling Tester.testWhatever(). Alright, lets try changing whois() to be external...

[FAIL. Reason: Revert] testWhatever() (gas: 4945)
Logs:
  0x00a329c0648769a73afac7f9381e08fb43dbea72

Traces:
  [4945] Tester::testWhatever()
    ├─ [269] 0xb4c7…7e84::cb6ab4fa(0000000000000000000000000000000000000000000000000000000000000001) [delegatecall]
    │   └─ ← 0x00000000000000000000000000a329c0648769a73afac7f9381e08fb43dbea72
    ├─ emit log_address(: 0x00a329c0648769a73afac7f9381e08fb43dbea72)
    ├─ [88] 0xb4c7…7e84::_log_string("success")
    │   └─ ← ()
    └─ ← ()

Test result: FAILED. 0 passed; 1 failed; finished in 258.15ms

Changing the address cast to ITest() to msg.sender doesn't fix the problem (it's that 0x00a... address) nor does explicitly inserting the literal 0x00a...

It looks like making one of the functions external results in an actual deployed library contract into which a delegatecall is made (for whois()). Note that the name of the call is not logged (instead its selector cb6ab4fa is used). Further, the call back into 0xb... fails.

Any thoughts? Also, the "bigger" issue is "what's Foundry's position on the insertion of debugging code into the developed contracts and libraries?"

PS: This methodology works "ok" (it's ugly but ...) until you try to call a logging function from inside a view function. Then, all hell breaks loose. Perhaps in the future Foundry should not use emits for logging, but rather, should provide a library that has a bunch of external view functions that implement logging and other useful things, e.g. at 0xb4c79daB8f259C7Aee6E5b2Aa729821864227e84?

[onbjerg]

Somewhat surprising, since the docs would imply msg.sender for calls from the test functions is 0xb4c79daB8f259C7Aee6E5b2Aa729821864227e84

This is not the case, I think you might have confused the sender and the test address. The docs state that the test is at address 0xb4c79daB8f259C7Aee6E5b2Aa729821864227e84, and 0x00a329c0648769a73afac7f9381e08fb43dbea72 is the address that calls the test.

When you call a library function it is usually a delegatecall. I'm not sure what it is for an internal function, maybe a normal call? Anyway, the reason you see a different msg.sender when you mark the function external is because the function is now called via delegatecall, so msg.sender is preserved from the original call, where msg.sender is 0x00a...

Perhaps in the future Foundry should not use emits for logging, but rather, should provide a library that has a bunch of external view functions that implement logging and other useful things, e.g. at 0xb4c79daB8f259C7Aee6E5b2Aa729821864227e84?

You can either:

• Emit the log directly. This works fine, even if a bit tedious, since debug logs are not meant to be pushed to production.
• Use console.sol from Hardhat (or the patched console2.sol version from Forge Std), which is basically what you describe. It's a library that calls a static address with some data to log.

[aathan]

Oh, also, lets not lose track of this: Should the tree view have been able to include more than just the selector in the delegatecall line? Seems like the component that emits this would have known the library ABI into which the delegate call was made, so as to print a more helpful line there.

[aathan]

FYI, performing a search (using the looking glass icon) on the Foundry book brings up only two mentions of 0x00a329c0648769a73afac7f9381e08fb43dbea72 and they are both in the configuration sections of the book (I.e., mentioned in passing). Meanwhile, this text appears regarding the other address:

Tests are deployed to 0xb4c79daB8f259C7Aee6E5b2Aa729821864227e84. If you deploy a contract within your test, then 0xb4c...7e84 will be its deployer. If the contract deployed within a test gives special permissions to its deployer, such as Ownable.sol's onlyOwner modifier, then the test contract 0xb4c...7e84 will have those permissions.

Given no mention of other special addresses it therefore seemed reasonable to assume that the msg.sender would also be that address (through some hack for the purposes of the test environment). I saw someone comment that the Foundry book is considered out of date, but perhaps some key edits should still be made (like mentioning this issue).

Separately, no, directly emitting the log is not an option because emits are state changing, and therefore cannot be done in view functions. I'll look for console2.sol (it's not in the forge-std I pulled from github). Thank you for the pointer! This is what I was looking for.

I won't go looking now to confirm, but forge-std was not something I ran into right away when diving into Foundry. It probably should be mentioned in README.md if it isn't.

Separately, I'm not sure I understand why the call back into 0xb4's logging function after the delegatecall into the library failed. It seems to me that should have worked.

[onbjerg]

Given no mention of other special addresses it therefore seemed reasonable to assume that the msg.sender would also be that address (through some hack for the purposes of the test environment). I saw someone comment that the Foundry book is considered out of date, but perhaps some key edits should still be made (like mentioning this issue).

It is no longer super out of date. That passage also says:

Tests are deployed to 0xb4c79daB8f259C7Aee6E5b2Aa729821864227e84. If you deploy a contract within your test, then 0xb4c...7e84 will be its deployer.

So, msg.sender is the caller of other contracts (not the test contract itself), but libraries are a special case since they use delegatecall as mentioned in my other comment (so msg.sender in that case will be the address that called the test contract)

I won't go looking now to confirm, but forge-std was not something I ran into right away when diving into Foundry. It probably should be mentioned in README.md if it isn't.

We mostly rely on Forge Std in the book now, so it is mentioned there

[aathan]

You're right, forge-std is mentioned prominently in the book. I think what happened for me is that console.log is not discussed at length (only its existence), and I thought the emit log items mentioned in the DSTest section was "it."

Listen, my comments are not meant either arguments or complaints. When learning new systems I take notice of the path I take through the docs and tools as I come up to speed, and try to improve that road by adding missing road signs. That's all.

AFAIK that 0x00a address is mentioned nowhere but in the config section of the foundry book. I'll figure out where the source to the book lives and submit a doc PR. IMHO it would also not hurt to mention forge-std in the foundry README.md given its prominence to effective testing with forge--it should probably be installed by most users. Not everyone opens the book (though they should).

Thanks again.

[onbjerg]

I think we're talking past each other here, I am not taking your comments as complaints, and if you feel like we should mention some of this more prominently in the book I consider that valuable information 😄 I'm sorry if I came off as dismissive in any way, that was not my intention

The book is in https://github.com/foundry-rs/book - feel free to open an issue if something is lacking/unclear

[aathan]

I'll try to do more than that when time allows, and actually offer some additional text. The other thing that may be different for my learning curve than others' is that I do not come to Foundry from a hardhat or truffle background. This is literally the first tool I've used for Solidity testing. That may explain why reading merely that console.log is a "hardhat like" module flew over my head, and allowed me to believe emit log_ was what exists therein.