Debug buffer formatting for Substrate (#1188)

integration/solana/runtime_errors.spec.ts

@@ -24,7 +24,8 @@ describe('Runtime Errors', function () {
         }
         catch (e: any) {
             const logs = e.simulationResponse.logs;
-            expect(logs).toContain("Program log: storage index out of bounds in runtime_errors.sol:42:10");
+            expect(logs).toContain(`Program log: runtime_error: storage index out of bounds in runtime_errors.sol:42:11-12,
+`);
         }
 
         try {
@@ -32,14 +33,16 @@ describe('Runtime Errors', function () {
         }
         catch (e: any) {
             const logs = e.simulationResponse.logs;
-            expect(logs).toContain("Program log: storage array index out of bounds in runtime_errors.sol:49:18");
+            expect(logs).toContain(`Program log: runtime_error: storage array index out of bounds in runtime_errors.sol:49:19-23,
+`);
         }
 
         try {
             let res = await program.methods.popEmptyStorage().accounts({ dataAccount: storage.publicKey }).simulate();
         } catch (e: any) {
             const logs = e.simulationResponse.logs;
-            expect(logs).toContain("Program log: pop from empty storage array in runtime_errors.sol:61:8")
+            expect(logs).toContain(`Program log: runtime_error: pop from empty storage array in runtime_errors.sol:61:9-12,
+`)
 
         }
 
@@ -47,7 +50,8 @@ describe('Runtime Errors', function () {
             let res = await program.methods.invalidInstruction().accounts({ dataAccount: storage.publicKey }).simulate();
         } catch (e: any) {
             const logs = e.simulationResponse.logs;
-            expect(logs).toContain("Program log: reached invalid instruction in runtime_errors.sol:108:12")
+            expect(logs).toContain(`Program log: runtime_error: reached invalid instruction in runtime_errors.sol:108:13-22,
+`)
 
         }
 
@@ -55,7 +59,8 @@ describe('Runtime Errors', function () {
             let res = await program.methods.byteCastFailure(new BN(33)).accounts({ dataAccount: storage.publicKey }).simulate();
         } catch (e: any) {
             const logs = e.simulationResponse.logs;
-            expect(logs).toContain("Program log: bytes cast error in runtime_errors.sol:114:22")
+            expect(logs).toContain(`Program log: runtime_error: bytes cast error in runtime_errors.sol:114:23-40,
+`)
 
         }
 
@@ -63,28 +68,32 @@ describe('Runtime Errors', function () {
             let res = await program.methods.iWillRevert().accounts({ dataAccount: storage.publicKey }).simulate();
         } catch (e: any) {
             const logs = e.simulationResponse.logs;
-            expect(logs).toContain("Program log: revert encountered in runtime_errors.sol:76:8")
+            expect(logs).toContain(`Program log: runtime_error: revert encountered in runtime_errors.sol:76:9-15,
+`)
         }
 
         try {
             let res = await program.methods.assertTest(new BN(9)).accounts({ dataAccount: storage.publicKey }).simulate();
         } catch (e: any) {
             const logs = e.simulationResponse.logs;
-            expect(logs).toContain("Program log: assert failure in runtime_errors.sol:35:15")
+            expect(logs).toContain(`Program log: runtime_error: assert failure in runtime_errors.sol:35:16-24,
+`)
         }
 
         try {
             let res = await program.methods.writeIntegerFailure(new BN(1)).accounts({ dataAccount: storage.publicKey }).simulate();
         } catch (e: any) {
             const logs = e.simulationResponse.logs;
-            expect(logs).toContain("Program log: integer too large to write in buffer in runtime_errors.sol:81:17")
+            expect(logs).toContain(`Program log: runtime_error: integer too large to write in buffer in runtime_errors.sol:81:18-31,
+`)
         }
 
         try {
             let res = await program.methods.writeBytesFailure(new BN(9)).accounts({ dataAccount: storage.publicKey }).simulate();
         } catch (e: any) {
             const logs = e.simulationResponse.logs;
-            expect(logs).toContain("Program log: data does not fit into buffer in runtime_errors.sol:87:17")
+            expect(logs).toContain(`Program log: runtime_error: data does not fit into buffer in runtime_errors.sol:87:18-28,
+`)
         }
 
 
@@ -92,7 +101,8 @@ describe('Runtime Errors', function () {
             let res = await program.methods.readIntegerFailure(new BN(2)).accounts({ dataAccount: storage.publicKey }).simulate();
         } catch (e: any) {
             const logs = e.simulationResponse.logs;
-            expect(logs).toContain("Program log: read integer out of bounds in runtime_errors.sol:92:17")
+            expect(logs).toContain(`Program log: runtime_error: read integer out of bounds in runtime_errors.sol:92:18-30,
+`)
         }
 
 
@@ -100,7 +110,8 @@ describe('Runtime Errors', function () {
             let res = await program.methods.outOfBounds(new BN(19)).accounts({ dataAccount: storage.publicKey }).simulate();
         } catch (e: any) {
             const logs = e.simulationResponse.logs;
-            expect(logs).toContain("Program log: array index out of bounds in runtime_errors.sol:103:15")
+            expect(logs).toContain(`Program log: runtime_error: array index out of bounds in runtime_errors.sol:103:16-21,
+`)
         }
 
 
@@ -108,7 +119,8 @@ describe('Runtime Errors', function () {
             let res = await program.methods.truncFailure(new BN(99999999999999)).accounts({ dataAccount: storage.publicKey }).simulate();
         } catch (e: any) {
             const logs = e.simulationResponse.logs;
-            expect(logs).toContain("Program log: truncated type overflows in runtime_errors.sol:97:36")
+            expect(logs).toContain(`Program log: runtime_error: truncated type overflows in runtime_errors.sol:97:37-42,
+`)
         }
 
         let child_program = new PublicKey("Cre7AzxtwSxXwU2jekYtCAQ57DkBhY9SjGDLdcrwhAo6");
@@ -137,7 +149,8 @@ describe('Runtime Errors', function () {
                 .signers([payer]).simulate();
         } catch (e: any) {
             const logs = e.simulationResponse.logs
-            expect(logs).toContain("Program log: contract creation failed in runtime_errors.sol:71:12")
+            expect(logs).toContain(`Program log: runtime_error: contract creation failed in runtime_errors.sol:71:13-62,
+`)
         }
 
     });

integration/substrate/debug_buffer_format.sol

@@ -0,0 +1,12 @@
+contract DebugBuffer {
+    function multiple_prints() public {
+        print("Hello!");
+        print("I call seal_debug_message under the hood!");
+    }
+
+    function multiple_prints_then_revert() public {
+        print("Hello!");
+        print("I call seal_debug_message under the hood!");
+        revert("sesa!!!");
+    }
+}

integration/substrate/debug_buffer_format.spec.ts

@@ -0,0 +1,48 @@
+import { createConnection, deploy, aliceKeypair, debug_buffer } from "./index";
+import expect from 'expect';
+import { ContractPromise } from "@polkadot/api-contract";
+
+describe('Deploy debug_buffer_format.sol and test the debug buffer formatting', () => {
+    it('formats the debug buffer', async function () {
+
+        let conn = await createConnection();
+        const alice = aliceKeypair();
+
+
+        let deployed_contract = await deploy(
+            conn,
+            alice,
+            "DebugBuffer.contract",
+            BigInt(0)
+        );
+
+        let contract = new ContractPromise(
+            conn,
+            deployed_contract.abi,
+            deployed_contract.address
+        );
+
+
+
+        let res = await debug_buffer(conn, contract, "multiple_prints", [])
+        expect(res).toEqual(`print: Hello!,
+call: seal_debug_message=0,
+print: I call seal_debug_message under the hood!,
+call: seal_debug_message=0,
+`)
+
+
+        let res1 = await debug_buffer(conn, contract, "multiple_prints_then_revert", [])
+        expect(res1).toEqual(`print: Hello!,
+call: seal_debug_message=0,
+print: I call seal_debug_message under the hood!,
+call: seal_debug_message=0,
+runtime_error: sesa!!! revert encountered in debug_buffer_format.sol:10:9-15,
+call: seal_debug_message=0,
+`)
+
+
+
+        conn.disconnect();
+    });
+});

integration/substrate/package.json

@@ -5,7 +5,7 @@
   "main": "index.js",
   "scripts": {
     "test": "tsc; ts-mocha -t 20000 *.spec.ts",
-    "build": "parallel solang compile -v --target substrate --log-runtime-errors --math-overflow ::: *.sol test/*.sol",
+    "build": "parallel solang compile -v --target substrate --log-runtime-errors --math-overflow ::: *.sol test/*.sol;  solang compile debug_buffer_format.sol --target substrate -v --log-runtime-errors --log-api-return-codes",
     "build-ink": "docker run --rm -v $(pwd)/ink/caller:/opt/contract paritytech/contracts-ci-linux@sha256:2eaa0869c562adabcfc011a2f3ad6b2289cdd0b3a8923e24d29efd4452b397de cargo contract build --manifest-path /opt/contract/Cargo.toml"
   },
   "contributors": [

integration/substrate/runtime_errors.spec.ts

@@ -1,92 +1,107 @@
 import { createConnection, deploy, aliceKeypair, debug_buffer } from "./index";
 import expect from 'expect';
 import { ContractPromise } from "@polkadot/api-contract";
-import path = require("path")
 
 describe('Deploy runtime_errors.sol and test the debug buffer', () => {
-  it('logs errors to the debug buffer', async function () {
+    it('logs errors to the debug buffer', async function () {
 
-    let conn = await createConnection();
-    const alice = aliceKeypair();
+        let conn = await createConnection();
+        const alice = aliceKeypair();
 
 
-    let deployed_contract = await deploy(
-      conn,
-      alice,
-      "RuntimeErrors.contract",
-      BigInt(0)
-    );
+        let deployed_contract = await deploy(
+            conn,
+            alice,
+            "RuntimeErrors.contract",
+            BigInt(0)
+        );
 
-    let contract = new ContractPromise(
-      conn,
-      deployed_contract.abi,
-      deployed_contract.address
-    );
+        let contract = new ContractPromise(
+            conn,
+            deployed_contract.abi,
+            deployed_contract.address
+        );
 
-    let child_contract = await deploy(conn, alice, 'child.contract', BigInt(0));
+        let child_contract = await deploy(conn, alice, 'child.contract', BigInt(0));
 
-    let res = await debug_buffer(conn, contract, "get_storage_bytes", [])
-    expect(res).toEqual("storage array index out of bounds in runtime_errors.sol:46:18")
+        let res = await debug_buffer(conn, contract, `get_storage_bytes`, [])
+        expect(res).toEqual(`runtime_error: storage array index out of bounds in runtime_errors.sol:46:19-23,
+`)
 
-    let res1 = await debug_buffer(conn, contract, "transfer_abort", [])
-    expect(res1).toEqual("value transfer failure in runtime_errors.sol:53:28")
+        let res1 = await debug_buffer(conn, contract, `transfer_abort`, [])
+        expect(res1).toEqual(`runtime_error: value transfer failure in runtime_errors.sol:53:29-31,
+`)
 
 
-    let res2 = await debug_buffer(conn, contract, "pop_empty_storage", [])
-    expect(res2).toEqual("pop from empty storage array in runtime_errors.sol:58:12")
+        let res2 = await debug_buffer(conn, contract, `pop_empty_storage`, [])
+        expect(res2).toEqual(`runtime_error: pop from empty storage array in runtime_errors.sol:58:13-16,
+`)
 
 
-    let res3 = await debug_buffer(conn, contract, "call_ext", [child_contract.address])
-    expect(res3).toEqual("external call failed in runtime_errors.sol:63:8")
+        let res3 = await debug_buffer(conn, contract, `call_ext`, [child_contract.address])
+        expect(res3).toEqual(`runtime_error: external call failed in runtime_errors.sol:63:9-24,
+`)
 
 
-    let res4 = await debug_buffer(conn, contract, "create_child");
-    expect(res4).toEqual("contract creation failed in runtime_errors.sol:68:12")
+        let res4 = await debug_buffer(conn, contract, `create_child`);
+        expect(res4).toEqual(`runtime_error: contract creation failed in runtime_errors.sol:68:13-24,
+`)
 
 
-    let res5 = await debug_buffer(conn, contract, "set_storage_bytes", [])
-    expect(res5).toEqual("storage index out of bounds in runtime_errors.sol:39:10")
+        let res5 = await debug_buffer(conn, contract, `set_storage_bytes`, [])
+        expect(res5).toEqual(`runtime_error: storage index out of bounds in runtime_errors.sol:39:11-12,
+`)
 
 
-    let res6 = await debug_buffer(conn, contract, "dont_pay_me", [], 1);
-    expect(res6).toEqual("non payable function dont_pay_me received value")
+        let res6 = await debug_buffer(conn, contract, `dont_pay_me`, [], 1);
+        expect(res6).toEqual(`runtime_error: non payable function dont_pay_me received value,
+`)
 
 
-    let res7 = await debug_buffer(conn, contract, "assert_test", [9], 0);
-    expect(res7).toEqual("assert failure in runtime_errors.sol:32:15")
+        let res7 = await debug_buffer(conn, contract, `assert_test`, [9], 0);
+        expect(res7).toEqual(`runtime_error: assert failure in runtime_errors.sol:32:16-24,
+`)
 
 
-    let res8 = await debug_buffer(conn, contract, "i_will_revert", [], 0);
-    expect(res8).toEqual("revert encountered in runtime_errors.sol:77:8")
+        let res8 = await debug_buffer(conn, contract, `i_will_revert`, [], 0);
+        expect(res8).toEqual(`runtime_error: revert encountered in runtime_errors.sol:77:9-15,
+`)
 
 
-    let res9 = await debug_buffer(conn, contract, "write_integer_failure", [1], 0);
-    expect(res9).toEqual("integer too large to write in buffer in runtime_errors.sol:82:17")
+        let res9 = await debug_buffer(conn, contract, `write_integer_failure`, [1], 0);
+        expect(res9).toEqual(`runtime_error: integer too large to write in buffer in runtime_errors.sol:82:18-31,
+`)
 
 
-    let res10 = await debug_buffer(conn, contract, "write_bytes_failure", [9], 0);
-    expect(res10).toEqual("data does not fit into buffer in runtime_errors.sol:88:17")
+        let res10 = await debug_buffer(conn, contract, `write_bytes_failure`, [9], 0);
+        expect(res10).toEqual(`runtime_error: data does not fit into buffer in runtime_errors.sol:88:18-28,
+`)
 
 
-    let res11 = await debug_buffer(conn, contract, "read_integer_failure", [2], 0);
-    expect(res11).toEqual("read integer out of bounds in runtime_errors.sol:93:17")
+        let res11 = await debug_buffer(conn, contract, `read_integer_failure`, [2], 0);
+        expect(res11).toEqual(`runtime_error: read integer out of bounds in runtime_errors.sol:93:18-30,
+`)
 
 
-    let res12 = await debug_buffer(conn, contract, "trunc_failure", [BigInt("999999999999999999999999")], 0);
-    expect(res12).toEqual("truncated type overflows in runtime_errors.sol:98:36")
+        let res12 = await debug_buffer(conn, contract, `trunc_failure`, [BigInt(`999999999999999999999999`)], 0);
+        expect(res12).toEqual(`runtime_error: truncated type overflows in runtime_errors.sol:98:37-42,
+`)
 
 
-    let res13 = await debug_buffer(conn, contract, "out_of_bounds", [19], 0);
-    expect(res13).toEqual("array index out of bounds in runtime_errors.sol:104:15")
+        let res13 = await debug_buffer(conn, contract, `out_of_bounds`, [19], 0);
+        expect(res13).toEqual(`runtime_error: array index out of bounds in runtime_errors.sol:104:16-21,
+`)
 
 
-    let res14 = await debug_buffer(conn, contract, "invalid_instruction", [], 0);
-    expect(res14).toEqual("reached invalid instruction in runtime_errors.sol:109:12")
+        let res14 = await debug_buffer(conn, contract, `invalid_instruction`, [], 0);
+        expect(res14).toEqual(`runtime_error: reached invalid instruction in runtime_errors.sol:109:13-22,
+`)
 
 
-    let res15 = await debug_buffer(conn, contract, "byte_cast_failure", [33], 0);
-    expect(res15).toEqual("bytes cast error in runtime_errors.sol:115:22")
+        let res15 = await debug_buffer(conn, contract, `byte_cast_failure`, [33], 0);
+        expect(res15).toEqual(`runtime_error: bytes cast error in runtime_errors.sol:115:23-40,
+`)
 
-    conn.disconnect();
-  });
+        conn.disconnect();
+    });
 });

src/codegen/expression.rs

@@ -816,7 +816,13 @@ pub fn expression(
         } => {
             let expr = expression(&args[0], cfg, contract_no, func, ns, vartab, opt);
 
-            cfg.add(vartab, Instr::Print { expr });
+            let to_print = if ns.target.is_substrate() {
+                add_prefix_and_delimiter_to_print(expr)
+            } else {
+                expr
+            };
+
+            cfg.add(vartab, Instr::Print { expr: to_print });
 
             Expression::Poison
         }
@@ -1373,11 +1379,22 @@ fn require(
         Target::Solana | Target::Substrate { .. } => {
             if opt.log_runtime_errors {
                 if let Some(expr) = expr {
-                    let error_string =
-                        error_msg_with_loc(ns, " require condition failed", Some(expr.loc()));
+                    let prefix = b"runtime_error: ";
+                    let error_string = format!(
+                        " require condition failed in {},\n",
+                        ns.loc_to_string(false, &expr.loc())
+                    );
                     let print_expr = Expression::FormatString(
                         Loc::Codegen,
                         vec![
+                            (
+                                FormatArg::StringLiteral,
+                                Expression::BytesLiteral(
+                                    Loc::Codegen,
+                                    Type::Bytes(prefix.len() as u8),
+                                    prefix.to_vec(),
+                                ),
+                            ),
                             (FormatArg::Default, expr),
                             (
                                 FormatArg::StringLiteral,
@@ -1425,10 +1442,22 @@ fn revert(
 
     if opt.log_runtime_errors {
         if expr.is_some() {
-            let error_string = error_msg_with_loc(ns, " revert encountered", Some(loc));
+            let prefix = b"runtime_error: ";
+            let error_string = format!(
+                " revert encountered in {},\n",
+                ns.loc_to_string(false, &loc)
+            );
             let print_expr = Expression::FormatString(
                 Loc::Codegen,
                 vec![
+                    (
+                        FormatArg::StringLiteral,
+                        Expression::BytesLiteral(
+                            Loc::Codegen,
+                            Type::Bytes(prefix.len() as u8),
+                            prefix.to_vec(),
+                        ),
+                    ),
                     (FormatArg::Default, expr.clone().unwrap()),
                     (
                         FormatArg::StringLiteral,
@@ -3233,7 +3262,58 @@ pub(crate) fn log_runtime_error(
 ) {
     if report_error {
         let error_with_loc = error_msg_with_loc(ns, reason, Some(reason_loc));
-        let expr = string_to_expr(error_with_loc);
+        let expr = string_to_expr(error_with_loc + ",\n");
         cfg.add(vartab, Instr::Print { expr });
     }
 }
+
+fn add_prefix_and_delimiter_to_print(mut expr: Expression) -> Expression {
+    let prefix = b"print: ";
+    let delimiter = b",\n";
+
+    if let Expression::FormatString(loc, args) = &mut expr {
+        let mut new_vec = Vec::new();
+        new_vec.push((
+            FormatArg::StringLiteral,
+            Expression::BytesLiteral(
+                Loc::Codegen,
+                Type::Bytes(prefix.len() as u8),
+                prefix.to_vec(),
+            ),
+        ));
+        new_vec.append(args);
+        new_vec.push((
+            FormatArg::StringLiteral,
+            Expression::BytesLiteral(
+                Loc::Codegen,
+                Type::Bytes(delimiter.len() as u8),
+                delimiter.to_vec(),
+            ),
+        ));
+
+        Expression::FormatString(*loc, new_vec)
+    } else {
+        Expression::FormatString(
+            Loc::Codegen,
+            vec![
+                (
+                    FormatArg::StringLiteral,
+                    Expression::BytesLiteral(
+                        Loc::Codegen,
+                        Type::Bytes(prefix.len() as u8),
+                        prefix.to_vec(),
+                    ),
+                ),
+                (FormatArg::Default, expr),
+                (
+                    FormatArg::StringLiteral,
+                    Expression::BytesLiteral(
+                        Loc::Codegen,
+                        Type::Bytes(delimiter.len() as u8),
+                        delimiter.to_vec(),
+                    ),
+                ),
+            ],
+        )
+    }
+}

src/codegen/mod.rs

@@ -1375,16 +1375,8 @@ pub(super) fn error_msg_with_loc(ns: &Namespace, error: &str, loc: Option<Loc>)
     if let Some(loc) = loc {
         match loc {
             Loc::File(..) => {
-                let file_no = loc.file_no();
-                let curr_file = &ns.files[file_no];
-                let (line_no, offset) = curr_file.offset_to_line_column(loc.start());
-                format!(
-                    "{} in {}:{}:{}",
-                    error,
-                    curr_file.path.file_name().unwrap().to_str().unwrap(),
-                    line_no + 1,
-                    offset
-                )
+                let loc_from_file = ns.loc_to_string(false, &loc);
+                format!("runtime_error: {error} in {loc_from_file}")
             }
             _ => error.to_string(),
         }

src/emit/functions.rs

@@ -108,7 +108,7 @@ pub(super) fn abort_if_value_transfer<'a, T: TargetRuntime<'a> + ?Sized>(
 
     target.log_runtime_error(
         binary,
-        format!("non payable function {function_name} received value"),
+        format!("runtime_error: non payable function {function_name} received value"),
         None,
         ns,
     );

src/emit/solana/target.rs

@@ -2378,7 +2378,7 @@ impl<'a> TargetRuntime<'a> for SolanaTarget {
         }
 
         let error_with_loc = error_msg_with_loc(ns, &reason_string, reason_loc);
-        let custom_error = string_to_basic_value(bin, ns, error_with_loc);
+        let custom_error = string_to_basic_value(bin, ns, error_with_loc + ",\n");
         self.print(
             bin,
             bin.vector_bytes(custom_error),

src/emit/substrate/mod.rs

@@ -1800,9 +1800,11 @@ fn log_return_code(binary: &Binary, api: &'static str, code: IntValue) {
 
     emit_context!(binary);
 
-    let fmt = format!("{api}=");
+    let fmt = format!("call: {api}=");
     let msg = fmt.as_bytes();
-    let length = i32_const!(msg.len() as u64 + 16);
+    let delimiter = b",\n";
+    let delimiter_length = delimiter.len();
+    let length = i32_const!(msg.len() as u64 + 16 + delimiter_length as u64);
     let out_buf =
         binary
             .builder
@@ -1830,6 +1832,25 @@ fn log_return_code(binary: &Binary, api: &'static str, code: IntValue) {
         .unwrap()
         .into_pointer_value();
 
+    let delimiter_string = binary.emit_global_string("delimiter", delimiter, true);
+    let lim_len = binary
+        .context
+        .i32_type()
+        .const_int(delimiter_length as u64, false);
+    call!(
+        "__memcpy",
+        &[
+            out_buf_offset.into(),
+            delimiter_string.into(),
+            lim_len.into()
+        ]
+    );
+    out_buf_offset = unsafe {
+        binary
+            .builder
+            .build_gep(binary.context.i8_type(), out_buf_offset, &[lim_len], "")
+    };
+
     let msg_len = binary.builder.build_int_sub(
         binary
             .builder

src/emit/substrate/target.rs

@@ -1835,7 +1835,7 @@ impl<'a> TargetRuntime<'a> for SubstrateTarget {
         }
         emit_context!(bin);
         let error_with_loc = error_msg_with_loc(ns, &reason_string, reason_loc);
-        let custom_error = string_to_basic_value(bin, ns, error_with_loc);
+        let custom_error = string_to_basic_value(bin, ns, error_with_loc + ",\n");
         call!(
             "seal_debug_message",
             &[

src/sema/file.rs

@@ -22,16 +22,21 @@ impl File {
     }
 
     /// Give a position as a human readable position
-    pub fn loc_to_string(&self, start: usize, end: usize) -> String {
+    pub fn loc_to_string(&self, full_path: bool, start: usize, end: usize) -> String {
         let (from_line, from_column) = self.offset_to_line_column(start);
         let (to_line, to_column) = self.offset_to_line_column(end);
 
+        let path = if full_path {
+            format!("{self}")
+        } else {
+            self.file_name()
+        };
         if from_line == to_line && from_column == to_column {
-            format!("{}:{}:{}", self, from_line + 1, from_column + 1)
+            format!("{}:{}:{}", path, from_line + 1, from_column + 1)
         } else if from_line == to_line {
             format!(
                 "{}:{}:{}-{}",
-                self,
+                path,
                 from_line + 1,
                 from_column + 1,
                 to_column + 1
@@ -39,7 +44,7 @@ impl File {
         } else {
             format!(
                 "{}:{}:{}-{}:{}",
-                self,
+                path,
                 from_line + 1,
                 from_column + 1,
                 to_line + 1,
@@ -71,6 +76,10 @@ impl File {
             self.line_starts[line_no - 1] + column_no
         }
     }
+
+    pub fn file_name(&self) -> String {
+        self.path.file_name().unwrap().to_string_lossy().into()
+    }
 }
 
 impl fmt::Display for File {
@@ -87,9 +96,11 @@ impl fmt::Display for File {
 
 impl Namespace {
     /// Give a position as a human readable position
-    pub fn loc_to_string(&self, loc: &Loc) -> String {
+    pub fn loc_to_string(&self, full_path: bool, loc: &Loc) -> String {
         match loc {
-            Loc::File(file_no, start, end) => self.files[*file_no].loc_to_string(*start, *end),
+            Loc::File(file_no, start, end) => {
+                self.files[*file_no].loc_to_string(full_path, *start, *end)
+            }
             Loc::Builtin => String::from("builtin"),
             Loc::Codegen => String::from("codegen"),
             Loc::Implicit => String::from("implicit"),

src/sema/using.rs

@@ -174,8 +174,7 @@ pub(crate) fn using_decl(
                                 diagnostics.push(Diagnostic::error_with_note(
                                     using_function.loc,
                                     format!(
-                                        "user defined operator function for '{}' must have one bool return type",
-                                        oper,
+                                        "user defined operator function for '{oper}' must have one bool return type",
                                     ),
                                     loc,
                                     format!("definition of '{function_name}'"),
@@ -199,8 +198,7 @@ pub(crate) fn using_decl(
                             diagnostics.push(Diagnostic::error_with_note(
                                 using_function.loc,
                                 format!(
-                                    "user defined operator function for '{}' must have pure mutability",
-                                    oper,
+                                    "user defined operator function for '{oper}' must have pure mutability",
                                 ),
                                 loc,
                                 format!("definition of '{function_name}'"),

tests/solana_tests/runtime_errors.rs

@@ -154,7 +154,10 @@ contract calle_contract {
             value: BigInt::from(10u8),
         }],
     );
-    assert_eq!(vm.logs, "math overflow in test.sol:22:19");
+    assert_eq!(
+        vm.logs,
+        "runtime_error: math overflow in test.sol:22:20-29,\n"
+    );
     vm.logs.clear();
 
     _res = vm.function_must_fail(
@@ -164,18 +167,29 @@ contract calle_contract {
             value: BigInt::from(9u8),
         }],
     );
-    assert_eq!(vm.logs, "sesa require condition failed in test.sol:28:26");
+
+    assert_eq!(
+        vm.logs,
+        "runtime_error: sesa require condition failed in test.sol:28:27-33,\n"
+    );
+
     vm.logs.clear();
 
     _res = vm.function_must_fail("get_storage_bytes", &[]);
+
     assert_eq!(
         vm.logs,
-        "storage array index out of bounds in test.sol:48:18"
+        "runtime_error: storage array index out of bounds in test.sol:48:19-23,\n"
     );
+
     vm.logs.clear();
 
     _res = vm.function_must_fail("set_storage_bytes", &[]);
-    assert_eq!(vm.logs, "storage index out of bounds in test.sol:41:10");
+
+    assert_eq!(
+        vm.logs,
+        "runtime_error: storage index out of bounds in test.sol:41:11-12,\n"
+    );
     vm.logs.clear();
 
     _res = vm.function_must_fail(
@@ -185,7 +199,11 @@ contract calle_contract {
             value: BigInt::from(2u8),
         }],
     );
-    assert_eq!(vm.logs, "read integer out of bounds in test.sol:86:17");
+
+    assert_eq!(
+        vm.logs,
+        "runtime_error: read integer out of bounds in test.sol:86:18-30,\n"
+    );
     vm.logs.clear();
 
     _res = vm.function_must_fail(
@@ -195,15 +213,29 @@ contract calle_contract {
             value: BigInt::from(u128::MAX),
         }],
     );
-    assert_eq!(vm.logs, "truncated type overflows in test.sol:91:36");
+
+    assert_eq!(
+        vm.logs,
+        "runtime_error: truncated type overflows in test.sol:91:37-42,\n"
+    );
     vm.logs.clear();
 
     _res = vm.function_must_fail("invalid_instruction", &[]);
-    assert_eq!(vm.logs, "reached invalid instruction in test.sol:102:12");
+
+    assert_eq!(
+        vm.logs,
+        "runtime_error: reached invalid instruction in test.sol:102:13-22,\n"
+    );
+
     vm.logs.clear();
 
     _res = vm.function_must_fail("pop_empty_storage", &[]);
-    assert_eq!(vm.logs, "pop from empty storage array in test.sol:54:8");
+
+    assert_eq!(
+        vm.logs,
+        "runtime_error: pop from empty storage array in test.sol:54:9-12,\n"
+    );
+
     vm.logs.clear();
 
     _res = vm.function_must_fail(
@@ -213,7 +245,12 @@ contract calle_contract {
             value: BigInt::from(9u8),
         }],
     );
-    assert_eq!(vm.logs, "data does not fit into buffer in test.sol:81:17");
+
+    assert_eq!(
+        vm.logs,
+        "runtime_error: data does not fit into buffer in test.sol:81:18-28,\n"
+    );
+
     vm.logs.clear();
 
     _res = vm.function_must_fail(
@@ -223,7 +260,11 @@ contract calle_contract {
             value: BigInt::from(9u8),
         }],
     );
-    assert_eq!(vm.logs, "assert failure in test.sol:34:15");
+    println!("{}", vm.logs);
+    assert_eq!(
+        vm.logs,
+        "runtime_error: assert failure in test.sol:34:16-24,\n"
+    );
     vm.logs.clear();
 
     _res = vm.function_must_fail(
@@ -233,7 +274,12 @@ contract calle_contract {
             value: BigInt::from(19u8),
         }],
     );
-    assert_eq!(vm.logs, "array index out of bounds in test.sol:97:15");
+
+    assert_eq!(
+        vm.logs,
+        "runtime_error: array index out of bounds in test.sol:97:16-21,\n"
+    );
+
     vm.logs.clear();
 
     _res = vm.function_must_fail(
@@ -246,8 +292,9 @@ contract calle_contract {
 
     assert_eq!(
         vm.logs,
-        "integer too large to write in buffer in test.sol:75:17"
+        "runtime_error: integer too large to write in buffer in test.sol:75:18-31,\n"
     );
+
     vm.logs.clear();
 
     _res = vm.function_must_fail(
@@ -257,14 +304,28 @@ contract calle_contract {
             value: BigInt::from(33u8),
         }],
     );
-    assert_eq!(vm.logs, "bytes cast error in test.sol:110:22");
+
+    assert_eq!(
+        vm.logs,
+        "runtime_error: bytes cast error in test.sol:110:23-40,\n"
+    );
+
     vm.logs.clear();
 
     _res = vm.function_must_fail("i_will_revert", &[]);
-    assert_eq!(vm.logs, "revert encountered in test.sol:70:8");
+
+    assert_eq!(
+        vm.logs,
+        "runtime_error: revert encountered in test.sol:70:9-15,\n"
+    );
+
     vm.logs.clear();
 
     _res = vm.function_must_fail("create_child", &[]);
-    assert_eq!(vm.logs, "contract creation failed in test.sol:61:12");
+
+    assert_eq!(
+        vm.logs,
+        "runtime_error: contract creation failed in test.sol:61:13-36,\n"
+    );
     vm.logs.clear();
 }

tests/substrate_tests/calls.rs

@@ -791,6 +791,10 @@ fn log_api_call_return_values_works() {
     runtime.function("test", vec![]);
     assert_eq!(
         &runtime.printbuf,
-        "seal_instantiate=0hi!seal_debug_message=0seal_call=0"
+        r##"call: seal_instantiate=0,
+print: hi!,
+call: seal_debug_message=0,
+call: seal_call=0,
+"##
     );
 }

tests/substrate_tests/debug_buffer_format.rs

@@ -0,0 +1,48 @@
+// SPDX-License-Identifier: Apache-2.0
+
+use crate::build_solidity_with_options;
+
+#[test]
+fn debug_buffer_format() {
+    let mut runtime = build_solidity_with_options(
+        r#"contract DebugBuffer {
+            function multiple_prints() public {
+                print("Hello!");
+                print("I call seal_debug_message under the hood!");
+            }
+        
+            function multiple_prints_then_revert() public {
+                print("Hello!");
+                print("I call seal_debug_message under the hood!");
+                revert("sesa!!!");
+            }
+        }        
+    "#,
+        false,
+        true,
+        true,
+    );
+
+    runtime.function("multiple_prints", [].to_vec());
+    assert_eq!(
+        runtime.printbuf,
+        r#"print: Hello!,
+call: seal_debug_message=0,
+print: I call seal_debug_message under the hood!,
+call: seal_debug_message=0,
+"#
+    );
+
+    runtime.printbuf.clear();
+    runtime.function_expect_failure("multiple_prints_then_revert", [].to_vec());
+    assert_eq!(
+        runtime.printbuf,
+        r#"print: Hello!,
+call: seal_debug_message=0,
+print: I call seal_debug_message under the hood!,
+call: seal_debug_message=0,
+runtime_error: sesa!!! revert encountered in test.sol:10:17-23,
+call: seal_debug_message=0,
+"#
+    );
+}

tests/substrate_tests/errors.rs

@@ -158,49 +158,66 @@ fn errors() {
     );
 
     runtime.function_expect_failure("write_bytes_failure", 9u8.encode());
+
     assert_eq!(
         runtime.printbuf,
-        "data does not fit into buffer in test.sol:95:21"
+        "runtime_error: data does not fit into buffer in test.sol:95:22-32,\n"
     );
 
     runtime.printbuf.clear();
     runtime.function_expect_failure("math_overflow", 10u8.encode());
-    assert_eq!(runtime.printbuf, "math overflow in test.sol:16:23");
+
+    assert_eq!(
+        runtime.printbuf,
+        "runtime_error: math overflow in test.sol:16:24-33,\n"
+    );
 
     runtime.printbuf.clear();
     runtime.function_expect_failure("require_test", 9u8.encode());
+
     assert_eq!(
         runtime.printbuf,
-        "sesa require condition failed in test.sol:21:30"
+        "runtime_error: sesa require condition failed in test.sol:21:31-37,\n"
     );
 
     runtime.printbuf.clear();
     runtime.function_expect_failure("assert_test", 9u8.encode());
-    assert_eq!(runtime.printbuf, "assert failure in test.sol:27:19");
+
+    assert_eq!(
+        runtime.printbuf,
+        "runtime_error: assert failure in test.sol:27:20-28,\n"
+    );
 
     runtime.printbuf.clear();
     runtime.function_expect_failure("set_storage_bytes", Vec::new());
+
     assert_eq!(
         runtime.printbuf,
-        "storage index out of bounds in test.sol:34:14"
+        "runtime_error: storage index out of bounds in test.sol:34:15-16,\n"
     );
 
     runtime.printbuf.clear();
     runtime.function_expect_failure("get_storage_bytes", Vec::new());
+
     assert_eq!(
         runtime.printbuf,
-        "storage array index out of bounds in test.sol:41:22"
+        "runtime_error: storage array index out of bounds in test.sol:41:23-27,\n"
     );
 
     runtime.printbuf.clear();
     runtime.function_expect_failure("transfer_abort", Vec::new());
-    assert_eq!(runtime.printbuf, "value transfer failure in test.sol:48:32");
+
+    assert_eq!(
+        runtime.printbuf,
+        "runtime_error: value transfer failure in test.sol:48:33-35,\n"
+    );
 
     runtime.printbuf.clear();
     runtime.function_expect_failure("pop_empty_storage", Vec::new());
+
     assert_eq!(
         runtime.printbuf,
-        "pop from empty storage array in test.sol:53:16"
+        "runtime_error: pop from empty storage array in test.sol:53:17-20,\n"
     );
 
     runtime.vm.value = 3500;
@@ -209,63 +226,82 @@ fn errors() {
     runtime.printbuf.clear();
     runtime.vm.value = 0;
     runtime.function_expect_failure("create_child", Vec::new());
+
     assert_eq!(
         runtime.printbuf,
-        "contract creation failed in test.sol:65:17"
+        "runtime_error: contract creation failed in test.sol:65:18-52,\n"
     );
 
     runtime.printbuf.clear();
     runtime.function_expect_failure("i_will_revert", Vec::new());
-    assert_eq!(runtime.printbuf, "revert encountered in test.sol:84:12");
+
+    assert_eq!(
+        runtime.printbuf,
+        "runtime_error: revert encountered in test.sol:84:13-19,\n"
+    );
 
     runtime.printbuf.clear();
     runtime.function_expect_failure("write_integer_failure", 1u8.encode());
+
     assert_eq!(
         runtime.printbuf,
-        "integer too large to write in buffer in test.sol:89:21"
+        "runtime_error: integer too large to write in buffer in test.sol:89:22-35,\n"
     );
 
     runtime.printbuf.clear();
     runtime.function_expect_failure("invalid_instruction", Vec::new());
+
     assert_eq!(
         runtime.printbuf,
-        "reached invalid instruction in test.sol:116:16"
+        "runtime_error: reached invalid instruction in test.sol:116:17-26,\n"
     );
 
     runtime.printbuf.clear();
     runtime.function_expect_failure("out_of_bounds", 19u8.encode());
+
     assert_eq!(
         runtime.printbuf,
-        "array index out of bounds in test.sol:111:19"
+        "runtime_error: array index out of bounds in test.sol:111:20-25,\n"
     );
 
     runtime.printbuf.clear();
     runtime.function_expect_failure("trunc_failure", u128::MAX.encode());
+
     assert_eq!(
         runtime.printbuf,
-        "truncated type overflows in test.sol:105:40"
+        "runtime_error: truncated type overflows in test.sol:105:41-46,\n"
     );
 
     runtime.printbuf.clear();
     runtime.function_expect_failure("byte_cast_failure", 33u8.encode());
-    assert_eq!(runtime.printbuf, "bytes cast error in test.sol:124:26");
+
+    assert_eq!(
+        runtime.printbuf,
+        "runtime_error: bytes cast error in test.sol:124:27-44,\n"
+    );
 
     runtime.printbuf.clear();
     runtime.function_expect_failure("read_integer_failure", 2u32.encode());
+
     assert_eq!(
         runtime.printbuf,
-        "read integer out of bounds in test.sol:100:21"
+        "runtime_error: read integer out of bounds in test.sol:100:22-34,\n"
     );
 
     runtime.printbuf.clear();
     runtime.function_expect_failure("call_ext", Vec::new());
-    assert_eq!(runtime.printbuf, "external call failed in test.sol:59:12");
+
+    assert_eq!(
+        runtime.printbuf,
+        "runtime_error: external call failed in test.sol:59:13-41,\n"
+    );
 
     runtime.printbuf.clear();
     runtime.vm.value = 1;
     runtime.function_expect_failure("dont_pay_me", Vec::new());
+
     assert_eq!(
         runtime.printbuf,
-        "non payable function dont_pay_me received value"
+        "runtime_error: non payable function dont_pay_me received value,\n"
     );
 }

tests/substrate_tests/format.rs

@@ -18,13 +18,13 @@ fn output() {
 
     runtime.function("foo", true.encode());
 
-    assert_eq!(runtime.printbuf, "val:true");
+    assert_eq!(runtime.printbuf, "print: val:true,\n");
 
     runtime.printbuf.truncate(0);
 
     runtime.function("foo", false.encode());
 
-    assert_eq!(runtime.printbuf, "val:false");
+    assert_eq!(runtime.printbuf, "print: val:false,\n");
 
     let mut runtime = build_solidity(
         r##"
@@ -39,7 +39,7 @@ fn output() {
 
     runtime.function("foo", b"ABCD".to_vec().encode());
 
-    assert_eq!(runtime.printbuf, "bar:41424344");
+    assert_eq!(runtime.printbuf, "print: bar:41424344,\n");
 
     let mut runtime = build_solidity(
         r##"
@@ -54,7 +54,7 @@ fn output() {
 
     runtime.function("foo", b"\x01\x03\xfe\x07\x09".encode());
 
-    assert_eq!(runtime.printbuf, "bar:0103fe0709");
+    assert_eq!(runtime.printbuf, "print: bar:0103fe0709,\n");
 
     let mut runtime = build_solidity(
         r##"
@@ -71,7 +71,10 @@ fn output() {
 
     assert_eq!(
         runtime.printbuf,
-        format!("bar:ladida address:{}", hex::encode(runtime.vm.account))
+        format!(
+            "print: bar:ladida address:{},\n",
+            hex::encode(runtime.vm.account)
+        )
     );
 
     let mut runtime = build_solidity(
@@ -87,19 +90,19 @@ fn output() {
 
     runtime.function("foo", 0xcafedu64.encode());
 
-    assert_eq!(runtime.printbuf, "bar:0xcafed");
+    assert_eq!(runtime.printbuf, "print: bar:0xcafed,\n");
 
     runtime.printbuf.truncate(0);
 
     runtime.function("foo", 0x1u64.encode());
 
-    assert_eq!(runtime.printbuf, "bar:0x1");
+    assert_eq!(runtime.printbuf, "print: bar:0x1,\n");
 
     runtime.printbuf.truncate(0);
 
     runtime.function("foo", 0x0u64.encode());
 
-    assert_eq!(runtime.printbuf, "bar:0x0");
+    assert_eq!(runtime.printbuf, "print: bar:0x0,\n");
 
     let mut runtime = build_solidity(
         r##"
@@ -114,7 +117,7 @@ fn output() {
 
     runtime.function("foo", (-0xca5cadab1efeeb1eeffab1ei128).encode());
 
-    assert_eq!(runtime.printbuf, "bar:-0xca5cadab1efeeb1eeffab1e");
+    assert_eq!(runtime.printbuf, "print: bar:-0xca5cadab1efeeb1eeffab1e,\n");
 
     let mut runtime = build_solidity(
         r##"
@@ -132,7 +135,9 @@ fn output() {
 
     assert_eq!(
         runtime.printbuf,
-        "there is an old android joke which goes 0b111111 there is an old android joke which goes -0b111111 "
+        r##"print: there is an old android joke which goes 0b111111 ,
+print: there is an old android joke which goes -0b111111 ,
+"##
     );
 
     let mut runtime = build_solidity(
@@ -149,7 +154,12 @@ fn output() {
     runtime.function("foo", (102i64).encode());
     runtime.function("foo", (-102i64).encode());
 
-    assert_eq!(runtime.printbuf, "number:102 number:-102 ");
+    assert_eq!(
+        runtime.printbuf,
+        r##"print: number:102 ,
+print: number:-102 ,
+"##
+    );
 
     let mut runtime = build_solidity(
         r##"
@@ -164,20 +174,25 @@ fn output() {
 
     runtime.function("foo", (8462643383279502884i128).encode());
 
-    assert_eq!(runtime.printbuf, "number:8462643383279502884 ");
+    assert_eq!(runtime.printbuf, "print: number:8462643383279502884 ,\n");
 
     runtime.printbuf.truncate(0);
 
     runtime.function("foo", (18462643383279502884i128).encode());
 
-    assert_eq!(runtime.printbuf, "number:18462643383279502884 ");
+    assert_eq!(runtime.printbuf, "print: number:18462643383279502884 ,\n");
 
     runtime.printbuf.truncate(0);
 
     runtime.function("foo", (3141592653589793238462643383279502884i128).encode());
     runtime.function("foo", (-3141592653589793238462643383279502884i128).encode());
 
-    assert_eq!(runtime.printbuf, "number:3141592653589793238462643383279502884 number:-3141592653589793238462643383279502884 ");
+    assert_eq!(
+        runtime.printbuf,
+        r##"print: number:3141592653589793238462643383279502884 ,
+print: number:-3141592653589793238462643383279502884 ,
+"##
+    );
 
     runtime.printbuf.truncate(0);
 
@@ -207,7 +222,9 @@ fn output() {
 
     assert_eq!(
         runtime.printbuf,
-        "number:34708801425935723273264209958040357568512 number:-34708801425935723273264209958040357568512 "
+        r##"print: number:34708801425935723273264209958040357568512 ,
+print: number:-34708801425935723273264209958040357568512 ,
+"##
     );
 
     runtime.printbuf.truncate(0);
@@ -217,7 +234,9 @@ fn output() {
 
     assert_eq!(
         runtime.printbuf,
-        "number:0x10200000000000000000000000000000000 number:34708801425935723273264209958040357568512 "
+        r##"print: number:0x10200000000000000000000000000000000 ,
+print: number:34708801425935723273264209958040357568512 ,
+"##
     );
 
     runtime.function("e", Vec::new());

tests/substrate_tests/mod.rs

@@ -10,6 +10,7 @@ mod arrays;
 mod builtins;
 mod calls;
 mod contracts;
+mod debug_buffer_format;
 mod errors;
 mod events;
 mod first;

tests/substrate_tests/strings.rs

@@ -610,7 +610,10 @@ fn string_escape() {
 
     runtime.function("カラス$", Vec::new());
 
-    assert_eq!(runtime.printbuf, " € A \u{c}\u{8}\r\n\u{b}\\'\"\t");
+    assert_eq!(
+        runtime.printbuf,
+        "print:  € A \u{c}\u{8}\r\n\u{b}\\'\"\t,\n"
+    );
 }
 
 #[test]