1
  • No, it's not about my own log entries via ILogger or Console.. The application doesn't even come that far.
  • No, I can't use third-party diagnostics like EventPipe, PerfView, ...

The following is given

  • I'm trying to run a simple dotnet application inside an SGX enclave.
  • For this I use Gramine
  • Now I've reached a point where I can no longer identify any errors, but the SIGABRT still occurs
  • The dotnet application is executed in the Docker container via ENTRYPOINT ["dotnet", "my-benchmark-app.dll"]

How can I either:

  • set to some verbose log during build (dotnet publish -c debug -o /app -r linux-x64 --self-contained false) where everything (GC Heap Allocation, Assembly-Loading, ...) from the application, before my part starts, is logged ?
  • set to any verbose log during startup?

Although it's irrelevant to my actual question, here's the "Linux" log

2022-10-13T11:45:11.643171952Z [P1:T1:dotnet] trace: ---- return from mmap(...) = 0x7ccce000
2022-10-13T11:45:11.643263885Z [P1:T1:dotnet] trace: ---- mprotect(0x7cd33000, 0x16c000, PROT_NONE) ...
2022-10-13T11:45:11.643278269Z [P1:T1:dotnet] trace: ---- return from mprotect(...) = 0x0
2022-10-13T11:45:11.643281345Z [P1:T1:dotnet] trace: ---- mmap(0x7cd33000, 0xe5000, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 61, 0x65000) ...
2022-10-13T11:45:11.646949186Z [P1:T1:dotnet] trace: ---- return from mmap(...) = 0x7cd33000
2022-10-13T11:45:11.647032917Z [P1:T1:dotnet] trace: ---- mmap(0x7ce18000, 0x86000, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 61, 0x14a000) ...
2022-10-13T11:45:11.649155700Z [P1:T1:dotnet] trace: ---- return from mmap(...) = 0x7ce18000
2022-10-13T11:45:11.649229577Z [P1:T1:dotnet] trace: ---- mmap(0x7ce9f000, 0x13000, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 61, 0x1d0000) ...
2022-10-13T11:45:11.649600872Z [P1:T1:dotnet] trace: ---- return from mmap(...) = 0x7ce9f000
2022-10-13T11:45:11.649669310Z [P1:T1:dotnet] trace: ---- mmap(0x7ceb2000, 0x11c0, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_FIXED, -1, 0x0) ...
2022-10-13T11:45:11.649680962Z [P1:T1:dotnet] trace: ---- return from mmap(...) = 0x7ceb2000
2022-10-13T11:45:11.649683095Z [P1:T1:dotnet] trace: ---- close(61) = 0x0
2022-10-13T11:45:11.649685679Z [P1:T1:dotnet] debug: glibc register library /usr/lib/x86_64-linux-gnu/libicuuc.so.66 loaded at 0x7ccce000
2022-10-13T11:45:11.649974673Z [P1:T1:dotnet] debug: append_r_debug: adding file:/usr/lib/x86_64-linux-gnu/libicuuc.so.66 at 0x7ccce000
2022-10-13T11:45:11.649981074Z [P1:T1:dotnet] trace: ---- openat(AT_FDCWD, "/gramine/meson_build_output/lib/x86_64-linux-gnu/gramine/runtime/glibc/libicudata.so.66", O_RDONLY|0x80000, 0000) = -2
2022-10-13T11:45:11.663166969Z [P1:T8:dotnet] trace: ---- return from futex(...) = -110
2022-10-13T11:45:11.663270599Z [P1:T8:dotnet] trace: ---- futex(0x7d7376d0, FUTEX_PRIVATE|FUTEX_WAKE, 1, 0, 0x7d737718, 0) ...
2022-10-13T11:45:11.663284718Z [P1:T8:dotnet] trace: ---- return from futex(...) = 0x0
2022-10-13T11:45:11.663287558Z [P1:T8:dotnet] trace: ---- clock_gettime(1, 0x7d382ab0) = 0x0
2022-10-13T11:45:11.663300234Z [P1:T8:dotnet] trace: ---- futex(0x7d737720, FUTEX_PRIVATE|FUTEX_WAIT_BITSET, 0, 0x7d382ab0, 0, -1) ...
2022-10-13T11:45:11.763774179Z [P1:T8:dotnet] trace: ---- return from futex(...) = -110
2022-10-13T11:45:11.764118534Z [P1:T8:dotnet] trace: ---- futex(0x7d7376d0, FUTEX_PRIVATE|FUTEX_WAKE, 1, 0, 0x7d737718, 0) ...
2022-10-13T11:45:11.764180309Z [P1:T8:dotnet] trace: ---- return from futex(...) = 0x0
2022-10-13T11:45:11.764790845Z [P1:T8:dotnet] trace: ---- mprotect(0x87440000, 0x1000, PROT_READ|PROT_WRITE) ...
2022-10-13T11:45:11.764797744Z [P1:T8:dotnet] trace: ---- return from mprotect(...) = 0x0
2022-10-13T11:45:11.764800298Z [P1:T8:dotnet] trace: ---- madvise(0x87440000, 0x1000, MADV_DODUMP) = -38
2022-10-13T11:45:11.764802681Z [P1:T8:dotnet] trace: ---- mprotect(0x87440000, 0x1000, PROT_READ|PROT_WRITE|PROT_EXEC) ...
2022-10-13T11:45:11.764804860Z [P1:T8:dotnet] trace: ---- return from mprotect(...) = 0x0
2022-10-13T11:45:11.764807022Z [P1:T8:dotnet] trace: ---- mprotect(0x87441000, 0x1000, PROT_READ|PROT_WRITE) ...
2022-10-13T11:45:11.764809079Z [P1:T8:dotnet] trace: ---- return from mprotect(...) = 0x0
2022-10-13T11:45:11.764811144Z [P1:T8:dotnet] trace: ---- madvise(0x87441000, 0x1000, MADV_DODUMP) = -38
2022-10-13T11:45:11.764813125Z [P1:T8:dotnet] trace: ---- mprotect(0x87441000, 0x1000, PROT_READ|PROT_WRITE|PROT_EXEC) ...
2022-10-13T11:45:11.764815164Z [P1:T8:dotnet] trace: ---- return from mprotect(...) = 0x0
2022-10-13T11:45:11.764817478Z [P1:T8:dotnet] trace: ---- sched_yield() = 0x0
2022-10-13T11:45:11.764819500Z [P1:T8:dotnet] trace: ---- clock_gettime(1, 0x7d382880) = 0x0
2022-10-13T11:45:11.764821874Z [P1:T8:dotnet] trace: ---- futex(0x7d737720, FUTEX_PRIVATE|FUTEX_WAIT_BITSET, 0, 0x7d382880, 0, -1) ...
2022-10-13T11:45:11.866719786Z [P1:T1:dotnet] trace: ---- openat(AT_FDCWD, "/usr/lib/x86_64-linux-gnu/libicudata.so.66", O_RDONLY|0x80000, 0000) = 0x3d
2022-10-13T11:45:11.867011802Z [P1:T1:dotnet] trace: ---- read(61, 0x80338c78, 0x340) ...
2022-10-13T11:45:11.867029685Z [P1:T1:dotnet] trace: ---- return from read(...) = 0x340
2022-10-13T11:45:11.867033192Z [P1:T1:dotnet] trace: ---- newfstatat(61, "", 0x80338b10, 4096) = 0x0
2022-10-13T11:45:11.867036330Z [P1:T1:dotnet] trace: ---- mmap(0, 0x1ac0010, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 61, 0x0) ...
2022-10-13T11:45:12.009774941Z [P1:T1:dotnet] trace: ---- return from mmap(...) = 0x7b20d000
2022-10-13T11:45:12.010553471Z [P1:T1:dotnet] trace: ---- mmap(0x7b20e000, 0x1000, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 61, 0x1000) ...
2022-10-13T11:45:12.010687604Z [P1:T1:dotnet] trace: ---- return from mmap(...) = 0x7b20e000
2022-10-13T11:45:12.010702641Z [P1:T1:dotnet] trace: ---- mmap(0x7b20f000, 0x1abd000, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 61, 0x2000) ...
2022-10-13T11:45:12.466285231Z [P1:T2:dotnet] trace: ---- return from poll(...) = 0x1
2022-10-13T11:45:12.466287200Z [P1:T2:dotnet] trace: ---- poll(0x7f4b2cf8, 1, 1000) ...
2022-10-13T11:45:12.466304667Z [P1:T2:dotnet] trace: ---- return from poll(...) = 0x1
2022-10-13T11:45:12.466311164Z [P1:T2:dotnet] trace: ---- poll(0x7f4b2cf8, 1, 1000) ...
2022-10-13T11:45:12.466334350Z [P1:T2:dotnet] trace: ---- return from poll(...) = 0x1
2022-10-13T11:45:12.466347133Z [P1:T2:dotnet] trace: ---- poll(0x7f4b2cf8, 1, 1000) ...
2022-10-13T11:45:12.466358458Z [P1:T2:dotnet] trace: ---- return from poll(...) = 0x1

... many times 'pool --> return'

2022-10-13T11:45:14.316036388Z [P1:T2:dotnet] trace: ---- poll(0x7f4b2cf8, 1, 1000) ...
2022-10-13T11:45:14.316048731Z [P1:T2:dotnet] trace: ---- return from poll(...) = 0x1
2022-10-13T11:45:14.316050729Z [P1:T2:dotnet] trace: ---- poll(0x7f4b2cf8, 1, 1000) ...
2022-10-13T11:45:14.316067436Z [P1:T2:dotnet] trace: ---- return from poll(...) = 0x1
2022-10-13T11:45:14.316078066Z [P1:T2:dotnet] trace: ---- poll(0x7f4b2cf8, 1, 1000) ...
2022-10-13T11:45:14.316091309Z [P1:T2:dotnet] trace: ---- return from poll(...) = 0x1
2022-10-13T11:45:14.316093243Z [P1:T2:dotnet] trace: ---- poll(0x7f4b2cf8, 1, 1000) ...
2022-10-13T11:45:14.318680412Z [P1:T2:dotnet] trace: ---- return from poll(...) = 0x1
2022-10-13T11:45:14.318685565Z [P1:T2:dotnet] trace: ---- poll(0x7f4b2cf8, 1, 1000) ...
2022-10-13T11:45:14.318690941Z [P1:T2:dotnet] trace: ---- return from poll(...) = 0x1
2022-10-13T11:45:14.318692774Z [P1:T2:dotnet] trace: ---- poll(0x7f4b2cf8, 1, 1000) ...
2022-10-13T11:45:14.318694593Z [P1:T1:dotnet] trace: ---- return from futex(...) = -110
2022-10-13T11:45:14.318696514Z [P1:T2:dotnet] trace: ---- return from poll(...) = 0x1
2022-10-13T11:45:14.318698323Z [P1:T2:dotnet] trace: ---- poll(0x7f4b2cf8, 1, 1000) ...
2022-10-13T11:45:14.318701825Z [P1:T1:dotnet] trace: ---- futex(0x7fc5ab70, FUTEX_PRIVATE|FUTEX_WAKE, 1, 0, 0x7fc5abb8, 0) ...
2022-10-13T11:45:14.318703957Z [P1:T1:dotnet] trace: ---- return from futex(...) = 0x0
2022-10-13T11:45:14.318706217Z [P1:T2:dotnet] trace: ---- return from poll(...) = 0x1
2022-10-13T11:45:14.318708044Z [P1:T2:dotnet] trace: ---- poll(0x7f4b2cf8, 1, 1000) ...
2022-10-13T11:45:14.318710364Z [P1:T1:dotnet] trace: ---- rt_sigaction([SIGABRT], 0x8033ab20, 0, 0x8) = 0x0
2022-10-13T11:45:14.318767543Z [P1:T2:dotnet] trace: ---- return from poll(...) = 0x1
2022-10-13T11:45:14.318769590Z [P1:T1:dotnet] trace: ---- rt_sigprocmask(UNBLOCK, [SIGABRT,], NULL, 0x8) = 0x0
2022-10-13T11:45:14.318771893Z [P1:T2:dotnet] trace: ---- poll(0x7f4b2cf8, 1, 1000) ...
2022-10-13T11:45:14.318774028Z [P1:T1:dotnet] trace: ---- gettid() = 0x1
2022-10-13T11:45:14.318777338Z [P1:T1:dotnet] trace: ---- getpid() = 0x1
2022-10-13T11:45:14.318779273Z [P1:T2:dotnet] trace: ---- return from poll(...) = 0x1
2022-10-13T11:45:14.318781149Z [P1:T2:dotnet] trace: ---- poll(0x7f4b2cf8, 1, 1000) ...
2022-10-13T11:45:14.318782955Z [P1:T1:dotnet] trace: ---- tgkill(1, 1, [SIGABRT]) = 0x0
2022-10-13T11:45:14.318784882Z [P1:T1:dotnet] debug: killed by signal 6
2022-10-13T11:45:14.318786759Z [P1:T2:dotnet] trace: ---- return from poll(...) = 0x1
2022-10-13T11:45:14.318788627Z [P1:T3:dotnet] trace: ---- return from read(...) = -512
2022-10-13T11:45:14.318790433Z [P1:T4:dotnet] trace: ---- return from futex(...) = -512
2022-10-13T11:45:14.318792356Z [P1:T8:dotnet] trace: ---- return from futex(...) = -512
2022-10-13T11:45:14.318794170Z [P1:T5:dotnet] trace: ---- return from futex(...) = -512
2022-10-13T11:45:14.318796043Z [P1:T6:dotnet] trace: ---- return from futex(...) = -512
2022-10-13T11:45:14.318798744Z [P1:T8:dotnet] debug: Creating pipe: pipe.srv:248aae68741c2f6494782fbdc900d87937f4b2fdd2d0d0591edea8244cd3bf5c
2022-10-13T11:45:14.318800585Z [P1:T7:dotnet] trace: ---- return from futex(...) = -512
2022-10-13T11:45:14.322990414Z [P1:T1:dotnet] debug: clearing POSIX locks for pid 1
2022-10-13T11:45:14.322996199Z [P1:T1:dotnet] debug: sync client shutdown: closing handles
2022-10-13T11:45:14.322998619Z [P1:T1:dotnet] debug: sync client shutdown: waiting for confirmation
2022-10-13T11:45:14.323000618Z [P1:T1:dotnet] debug: sync client shutdown: finished
2022-10-13T11:45:14.323507636Z [P1:T5:dotnet] debug: Installed async event at 1665661514316366
2022-10-13T11:45:14.323512699Z [P1:T6:dotnet] debug: Installed async event at 1665661514316395
2022-10-13T11:45:14.323514594Z [P1:T7:dotnet] debug: Installed async event at 1665661514316425
2022-10-13T11:45:14.323516507Z [P1:T4:dotnet] debug: Installed async event at 1665661514317402
2022-10-13T11:45:14.323518382Z [P1:T3:dotnet] debug: Installed async event at 1665661514316441
2022-10-13T11:45:14.323520312Z [P1:T2:dotnet] debug: Installed async event at 1665661514322701
2022-10-13T11:45:14.323522247Z [P1:T8:dotnet] debug: Installed async event at 1665661514316357
2022-10-13T11:45:14.323599373Z [P1:libos] debug: IPC worker: exiting worker thread
2022-10-13T11:45:14.323858732Z [P1:T1:dotnet] debug: process 1 exited with status 134
2022-10-13T11:45:14.323863664Z debug: PalProcessExit: Returning exit code 134
masterchris_99
  • 2,683
  • 7
  • 34
  • 55
  • 1
    You forgot to actually ask a question and went straight to the restrictions. What's the question? You tried to run a dotnet app in Docker and it crashed? Or did it exit immediately? What does the `Main` method do? – Panagiotis Kanavos Oct 14 '22 at 07:50
  • @PanagiotisKanavos Too bad. I thought I phrased the question better. It's not about debugging within my program. I contend that this is too complex to discuss and resolve here. My concern is to have the application log in such a way that I can log every little detail before my part is even loaded. – masterchris_99 Oct 14 '22 at 08:47

0 Answers0