executor.go 23 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538539540541542543544545546547548549550551552553554555556557558559560561562563564565566567568569570571572573574575576577578579580581582583584585586587588589590591592593594595596597598599600601602603604605606607608609610611612613614615616617618619620621622623624625626627628629630631632633634635636637638639640641642643644645646647648649650651652653654655656657658659660661662663664665666667668669670671672673674675676677678679680681682683684685686687688689690691692693694695696697698699700701702703704705706707708709710711712713714715716717718719720721722723724725726727728729730731732733734735736737738739740741742743744745746747748749750751752753754755756757758759760761762763764765766767768769770771772773774775776777778779780781782783784785786787788789790791792793794795796797798799800801802803804805806807808809810811812813814815816817818819820821822823824825826827828829830831832833834835836837838839840841842843844845846847848849850851852853854855856857858859860861862863864865866867868869870871872873874875876
  1. package executor
  2. import (
  3. acl "github.com/OliveTin/OliveTin/internal/acl"
  4. config "github.com/OliveTin/OliveTin/internal/config"
  5. "github.com/OliveTin/OliveTin/internal/entities"
  6. "github.com/google/uuid"
  7. log "github.com/sirupsen/logrus"
  8. "github.com/prometheus/client_golang/prometheus"
  9. "github.com/prometheus/client_golang/prometheus/promauto"
  10. "gopkg.in/yaml.v3"
  11. "bytes"
  12. "context"
  13. "fmt"
  14. "os"
  15. "os/exec"
  16. "path"
  17. "strings"
  18. "sync"
  19. "time"
  20. )
  21. const (
  22. DefaultExitCodeNotExecuted = -1337
  23. MaxTriggerDepth = 10
  24. )
  25. var (
  26. metricActionsRequested = promauto.NewCounter(prometheus.CounterOpts{
  27. Name: "olivetin_actions_requested_count",
  28. Help: "The actions requested count",
  29. })
  30. )
  31. type ActionBinding struct {
  32. ID string
  33. Action *config.Action
  34. Entity *entities.Entity
  35. ConfigOrder int
  36. IsOnDashboard bool
  37. }
  38. // Executor represents a helper class for executing commands. It's main method
  39. // is ExecRequest
  40. type Executor struct {
  41. logs map[string]*InternalLogEntry
  42. logsTrackingIdsByDate []string
  43. LogsByActionId map[string][]*InternalLogEntry
  44. logmutex sync.RWMutex
  45. MapActionIdToBinding map[string]*ActionBinding
  46. MapActionIdToBindingLock sync.RWMutex
  47. Cfg *config.Config
  48. listeners []listener
  49. chainOfCommand []executorStepFunc
  50. }
  51. // ExecutionRequest is a request to execute an action. It's passed to an
  52. // Executor. They're created from the api.
  53. type ExecutionRequest struct {
  54. Binding *ActionBinding
  55. Arguments map[string]string
  56. TrackingID string
  57. Tags []string
  58. Cfg *config.Config
  59. AuthenticatedUser *acl.AuthenticatedUser
  60. TriggerDepth int
  61. logEntry *InternalLogEntry
  62. finalParsedCommand string
  63. execArgs []string
  64. useDirectExec bool
  65. executor *Executor
  66. }
  67. // InternalLogEntry objects are created by an Executor, and represent the final
  68. // state of execution (even if the command is not executed). It's designed to be
  69. // easily serializable.
  70. type InternalLogEntry struct {
  71. Binding *ActionBinding
  72. BindingID string
  73. DatetimeStarted time.Time
  74. DatetimeFinished time.Time
  75. Output string
  76. TimedOut bool
  77. Blocked bool
  78. ExitCode int32
  79. Tags []string
  80. ExecutionStarted bool
  81. ExecutionFinished bool
  82. ExecutionTrackingID string
  83. Process *os.Process
  84. Username string
  85. Index int64
  86. EntityPrefix string
  87. ActionConfigTitle string // This is the title of the action as defined in the config, not the final parsed title.
  88. /*
  89. The following 3 properties are obviously on Action normally, but it's useful
  90. that logs are lightweight (so we don't need to have an action associated to
  91. logs, etc. Therefore, we duplicate those values here.
  92. */
  93. ActionTitle string
  94. ActionIcon string
  95. ActionId string
  96. }
  97. type executorStepFunc func(*ExecutionRequest) bool
  98. // DefaultExecutor returns an Executor, with a sensible "chain of command" for
  99. // executing actions.
  100. func DefaultExecutor(cfg *config.Config) *Executor {
  101. e := Executor{}
  102. e.Cfg = cfg
  103. e.logs = make(map[string]*InternalLogEntry)
  104. e.logsTrackingIdsByDate = make([]string, 0)
  105. e.LogsByActionId = make(map[string][]*InternalLogEntry)
  106. e.MapActionIdToBinding = make(map[string]*ActionBinding)
  107. e.chainOfCommand = []executorStepFunc{
  108. stepRequestAction,
  109. stepConcurrencyCheck,
  110. stepRateCheck,
  111. stepACLCheck,
  112. stepParseArgs,
  113. stepLogStart,
  114. stepExec,
  115. stepExecAfter,
  116. stepLogFinish,
  117. stepSaveLog,
  118. stepTrigger,
  119. }
  120. return &e
  121. }
  122. type listener interface {
  123. OnExecutionStarted(logEntry *InternalLogEntry)
  124. OnExecutionFinished(logEntry *InternalLogEntry)
  125. OnOutputChunk(o []byte, executionTrackingId string)
  126. OnActionMapRebuilt()
  127. }
  128. func (e *Executor) AddListener(m listener) {
  129. e.listeners = append(e.listeners, m)
  130. }
  131. // getPagingStartIndex calculates the starting index for log pagination.
  132. // Parameters:
  133. //
  134. // startOffset: The offset from the most recent log (0 means start from the most recent)
  135. // totalLogCount: Total number of logs available
  136. // count: Number of logs to retrieve
  137. //
  138. // Returns: The calculated starting index for pagination
  139. func getPagingStartIndex(startOffset int64, totalLogCount int64) int64 {
  140. var startIndex int64
  141. if startOffset <= 0 {
  142. startIndex = totalLogCount
  143. } else {
  144. startIndex = (totalLogCount - startOffset)
  145. if startIndex < 0 {
  146. startIndex = 1
  147. }
  148. }
  149. return startIndex - 1
  150. }
  151. type PagingResult struct {
  152. CountRemaining int64
  153. PageSize int64
  154. TotalCount int64
  155. StartOffset int64
  156. }
  157. func (e *Executor) GetLogTrackingIds(startOffset int64, pageCount int64) ([]*InternalLogEntry, *PagingResult) {
  158. pagingResult := &PagingResult{
  159. CountRemaining: 0,
  160. PageSize: pageCount,
  161. TotalCount: 0,
  162. StartOffset: startOffset,
  163. }
  164. e.logmutex.RLock()
  165. totalLogCount := int64(len(e.logsTrackingIdsByDate))
  166. pagingResult.TotalCount = totalLogCount
  167. startIndex := getPagingStartIndex(startOffset, totalLogCount)
  168. pageCount = min(totalLogCount, pageCount)
  169. endIndex := max(0, (startIndex-pageCount)+1)
  170. log.WithFields(log.Fields{
  171. "startOffset": startOffset,
  172. "pageCount": pageCount,
  173. "total": totalLogCount,
  174. "startIndex": startIndex,
  175. "endIndex": endIndex,
  176. }).Tracef("GetLogTrackingIds")
  177. trackingIds := make([]*InternalLogEntry, 0, pageCount)
  178. if totalLogCount > 0 {
  179. for i := endIndex; i <= startIndex; i++ {
  180. trackingIds = append(trackingIds, e.logs[e.logsTrackingIdsByDate[i]])
  181. }
  182. }
  183. e.logmutex.RUnlock()
  184. pagingResult.CountRemaining = endIndex
  185. return trackingIds, pagingResult
  186. }
  187. // isValidLogEntryForACL checks if a log entry has all required fields for ACL checking.
  188. func isValidLogEntryForACL(entry *InternalLogEntry) bool {
  189. return entry != nil && entry.Binding != nil && entry.Binding.Action != nil
  190. }
  191. // isLogEntryAllowedByACL checks if a log entry is allowed to be viewed by the user.
  192. func isLogEntryAllowedByACL(cfg *config.Config, user *acl.AuthenticatedUser, entry *InternalLogEntry) bool {
  193. return acl.IsAllowedLogs(cfg, user, entry.Binding.Action)
  194. }
  195. func (e *Executor) filterLogsByACL(cfg *config.Config, user *acl.AuthenticatedUser) []*InternalLogEntry {
  196. e.logmutex.RLock()
  197. defer e.logmutex.RUnlock()
  198. filtered := make([]*InternalLogEntry, 0, len(e.logsTrackingIdsByDate))
  199. for _, trackingId := range e.logsTrackingIdsByDate {
  200. entry := e.logs[trackingId]
  201. if !isValidLogEntryForACL(entry) {
  202. continue
  203. }
  204. if isLogEntryAllowedByACL(cfg, user, entry) {
  205. filtered = append(filtered, entry)
  206. }
  207. }
  208. return filtered
  209. }
  210. // paginateFilteredLogs applies pagination to a filtered list of logs and returns
  211. // the paginated results along with pagination metadata.
  212. func paginateFilteredLogs(filtered []*InternalLogEntry, startOffset int64, pageCount int64) ([]*InternalLogEntry, *PagingResult) {
  213. total := int64(len(filtered))
  214. paging := &PagingResult{PageSize: pageCount, TotalCount: total, StartOffset: startOffset}
  215. if total == 0 {
  216. paging.CountRemaining = 0
  217. return []*InternalLogEntry{}, paging
  218. }
  219. startIndex := getPagingStartIndex(startOffset, total)
  220. pageCount = min(total, pageCount)
  221. endIndex := max(0, (startIndex-pageCount)+1)
  222. out := make([]*InternalLogEntry, 0, pageCount)
  223. for i := endIndex; i <= startIndex && i < int64(len(filtered)); i++ {
  224. out = append(out, filtered[i])
  225. }
  226. paging.CountRemaining = endIndex
  227. return out, paging
  228. }
  229. // GetLogTrackingIdsACL returns logs filtered by ACL visibility for the user and
  230. // paginated correctly based on the filtered set.
  231. func (e *Executor) GetLogTrackingIdsACL(cfg *config.Config, user *acl.AuthenticatedUser, startOffset int64, pageCount int64) ([]*InternalLogEntry, *PagingResult) {
  232. filtered := e.filterLogsByACL(cfg, user)
  233. return paginateFilteredLogs(filtered, startOffset, pageCount)
  234. }
  235. func (e *Executor) GetLog(trackingID string) (*InternalLogEntry, bool) {
  236. e.logmutex.RLock()
  237. entry, found := e.logs[trackingID]
  238. e.logmutex.RUnlock()
  239. return entry, found
  240. }
  241. func (e *Executor) GetLogsByActionId(actionId string) []*InternalLogEntry {
  242. e.logmutex.RLock()
  243. logs, found := e.LogsByActionId[actionId]
  244. e.logmutex.RUnlock()
  245. if !found {
  246. return make([]*InternalLogEntry, 0)
  247. }
  248. return logs
  249. }
  250. func (e *Executor) SetLog(trackingID string, entry *InternalLogEntry) {
  251. e.logmutex.Lock()
  252. entry.Index = int64(len(e.logsTrackingIdsByDate))
  253. e.logs[trackingID] = entry
  254. e.logsTrackingIdsByDate = append(e.logsTrackingIdsByDate, trackingID)
  255. e.logmutex.Unlock()
  256. }
  257. // ExecRequest processes an ExecutionRequest
  258. func (e *Executor) ExecRequest(req *ExecutionRequest) (*sync.WaitGroup, string) {
  259. if req.AuthenticatedUser == nil {
  260. req.AuthenticatedUser = acl.UserGuest(req.Cfg)
  261. }
  262. req.executor = e
  263. req.logEntry = &InternalLogEntry{
  264. Binding: req.Binding,
  265. DatetimeStarted: time.Now(),
  266. ExecutionTrackingID: req.TrackingID,
  267. Output: "",
  268. ExitCode: DefaultExitCodeNotExecuted,
  269. ExecutionStarted: false,
  270. ExecutionFinished: false,
  271. ActionId: "",
  272. ActionTitle: "notfound",
  273. ActionIcon: "&#x1f4a9;",
  274. Username: req.AuthenticatedUser.Username,
  275. }
  276. _, isDuplicate := e.GetLog(req.TrackingID)
  277. if isDuplicate || req.TrackingID == "" {
  278. req.TrackingID = uuid.NewString()
  279. }
  280. // Update the log entry with the final tracking ID
  281. req.logEntry.ExecutionTrackingID = req.TrackingID
  282. log.Tracef("executor.ExecRequest(): %v", req)
  283. e.SetLog(req.TrackingID, req.logEntry)
  284. wg := new(sync.WaitGroup)
  285. wg.Add(1)
  286. go func() {
  287. e.execChain(req)
  288. defer wg.Done()
  289. }()
  290. return wg, req.TrackingID
  291. }
  292. func (e *Executor) execChain(req *ExecutionRequest) {
  293. for _, step := range e.chainOfCommand {
  294. if !step(req) {
  295. break
  296. }
  297. }
  298. req.logEntry.ExecutionFinished = true
  299. // This isn't a step, because we want to notify all listeners, irrespective
  300. // of how many steps were actually executed.
  301. notifyListenersFinished(req)
  302. }
  303. func getConcurrentCount(req *ExecutionRequest) int {
  304. concurrentCount := 0
  305. req.executor.logmutex.RLock()
  306. for _, log := range req.executor.GetLogsByActionId(req.Binding.Action.ID) {
  307. if !log.ExecutionFinished {
  308. concurrentCount += 1
  309. }
  310. }
  311. req.executor.logmutex.RUnlock()
  312. return concurrentCount
  313. }
  314. func stepConcurrencyCheck(req *ExecutionRequest) bool {
  315. concurrentCount := getConcurrentCount(req)
  316. // Note that the current execution is counted int the logs, so when checking we +1
  317. if concurrentCount >= (req.Binding.Action.MaxConcurrent + 1) {
  318. log.WithFields(log.Fields{
  319. "actionTitle": req.logEntry.ActionTitle,
  320. "concurrentCount": concurrentCount,
  321. "maxConcurrent": req.Binding.Action.MaxConcurrent,
  322. }).Warnf("Blocked from executing due to concurrency limit")
  323. req.logEntry.Output = "Blocked from executing due to concurrency limit"
  324. req.logEntry.Blocked = true
  325. return false
  326. }
  327. return true
  328. }
  329. func parseDuration(rate config.RateSpec) time.Duration {
  330. duration, err := time.ParseDuration(rate.Duration)
  331. if err != nil {
  332. log.Warnf("Could not parse duration: %v", rate.Duration)
  333. return -1 * time.Minute
  334. }
  335. return duration
  336. }
  337. //gocyclo:ignore
  338. func getExecutionsCount(rate config.RateSpec, req *ExecutionRequest) int {
  339. executions := -1 // Because we will find ourself when checking execution logs
  340. duration := parseDuration(rate)
  341. then := time.Now().Add(-duration)
  342. for _, logEntry := range req.executor.GetLogsByActionId(req.Binding.Action.ID) {
  343. // FIXME
  344. /*
  345. if logEntry.EntityPrefix != req.EntityPrefix {
  346. continue
  347. }
  348. */
  349. if logEntry.DatetimeStarted.After(then) && !logEntry.Blocked {
  350. executions += 1
  351. }
  352. }
  353. return executions
  354. }
  355. func stepRateCheck(req *ExecutionRequest) bool {
  356. for _, rate := range req.Binding.Action.MaxRate {
  357. executions := getExecutionsCount(rate, req)
  358. if executions >= rate.Limit {
  359. log.WithFields(log.Fields{
  360. "actionTitle": req.logEntry.ActionTitle,
  361. "executions": executions,
  362. "limit": rate.Limit,
  363. "duration": rate.Duration,
  364. }).Infof("Blocked from executing due to rate limit")
  365. req.logEntry.Output = "Blocked from executing due to rate limit"
  366. req.logEntry.Blocked = true
  367. return false
  368. }
  369. }
  370. return true
  371. }
  372. func stepACLCheck(req *ExecutionRequest) bool {
  373. canExec := acl.IsAllowedExec(req.Cfg, req.AuthenticatedUser, req.Binding.Action)
  374. if !canExec {
  375. req.logEntry.Output = "ACL check failed. Blocked from executing."
  376. req.logEntry.Blocked = true
  377. log.WithFields(log.Fields{
  378. "actionTitle": req.logEntry.ActionTitle,
  379. }).Warnf("ACL check failed. Blocked from executing.")
  380. }
  381. return canExec
  382. }
  383. func stepParseArgs(req *ExecutionRequest) bool {
  384. ensureArgumentMap(req)
  385. injectSystemArgs(req)
  386. if !hasBindingAndAction(req) {
  387. return fail(req, fmt.Errorf("cannot parse arguments: Binding or Action is nil"))
  388. }
  389. mangleInvalidArgumentValues(req)
  390. if hasExec(req) {
  391. return handleExecBranch(req)
  392. } else {
  393. return handleShellBranch(req)
  394. }
  395. }
  396. func handleExecBranch(req *ExecutionRequest) bool {
  397. args, err := parseActionExec(req.Arguments, req.Binding.Action, req.Binding.Entity)
  398. if err != nil {
  399. return fail(req, err)
  400. }
  401. req.useDirectExec = true
  402. req.execArgs = args
  403. return true
  404. }
  405. func handleShellBranch(req *ExecutionRequest) bool {
  406. if err := checkShellArgumentSafety(req.Binding.Action); err != nil {
  407. return fail(req, err)
  408. }
  409. cmd, err := parseActionArguments(req.Arguments, req.Binding.Action, req.Binding.Entity)
  410. if err != nil {
  411. return fail(req, err)
  412. }
  413. req.useDirectExec = false
  414. req.finalParsedCommand = cmd
  415. return true
  416. }
  417. func ensureArgumentMap(req *ExecutionRequest) {
  418. if req.Arguments == nil {
  419. req.Arguments = make(map[string]string)
  420. }
  421. }
  422. func injectSystemArgs(req *ExecutionRequest) {
  423. req.Arguments["ot_executionTrackingId"] = req.TrackingID
  424. req.Arguments["ot_username"] = req.AuthenticatedUser.Username
  425. }
  426. func hasBindingAndAction(req *ExecutionRequest) bool {
  427. return !(req.Binding == nil || req.Binding.Action == nil)
  428. }
  429. func hasExec(req *ExecutionRequest) bool {
  430. return len(req.Binding.Action.Exec) > 0
  431. }
  432. func fail(req *ExecutionRequest, err error) bool {
  433. req.logEntry.Output = err.Error()
  434. log.Warn(err.Error())
  435. return false
  436. }
  437. func stepRequestAction(req *ExecutionRequest) bool {
  438. metricActionsRequested.Inc()
  439. // If there is no binding or action, do not proceed. Leave default
  440. // log entry values (icon/title/id) and stop execution gracefully.
  441. if req.Binding == nil || req.Binding.Action == nil {
  442. log.Warnf("Action request has no binding/action; skipping execution")
  443. return false
  444. }
  445. req.logEntry.Binding = req.Binding
  446. req.logEntry.ActionConfigTitle = req.Binding.Action.Title
  447. req.logEntry.ActionTitle = entities.ParseTemplateWith(req.Binding.Action.Title, req.Binding.Entity)
  448. req.logEntry.ActionIcon = req.Binding.Action.Icon
  449. req.logEntry.ActionId = req.Binding.Action.ID
  450. req.logEntry.Tags = req.Tags
  451. req.executor.logmutex.Lock()
  452. if _, containsKey := req.executor.LogsByActionId[req.Binding.Action.ID]; !containsKey {
  453. req.executor.LogsByActionId[req.Binding.Action.ID] = make([]*InternalLogEntry, 0)
  454. }
  455. req.executor.LogsByActionId[req.Binding.Action.ID] = append(req.executor.LogsByActionId[req.Binding.Action.ID], req.logEntry)
  456. req.executor.logmutex.Unlock()
  457. log.WithFields(log.Fields{
  458. "actionTitle": req.logEntry.ActionTitle,
  459. "tags": req.Tags,
  460. }).Infof("Action requested")
  461. notifyListenersStarted(req)
  462. return true
  463. }
  464. func stepLogStart(req *ExecutionRequest) bool {
  465. log.WithFields(log.Fields{
  466. "actionTitle": req.logEntry.ActionTitle,
  467. "timeout": req.Binding.Action.Timeout,
  468. }).Infof("Action started")
  469. return true
  470. }
  471. func stepLogFinish(req *ExecutionRequest) bool {
  472. req.logEntry.ExecutionFinished = true
  473. log.WithFields(log.Fields{
  474. "actionTitle": req.logEntry.ActionTitle,
  475. "outputLength": len(req.logEntry.Output),
  476. "timedOut": req.logEntry.TimedOut,
  477. "exit": req.logEntry.ExitCode,
  478. }).Infof("Action finished")
  479. return true
  480. }
  481. func notifyListenersFinished(req *ExecutionRequest) {
  482. for _, listener := range req.executor.listeners {
  483. listener.OnExecutionFinished(req.logEntry)
  484. }
  485. }
  486. func notifyListenersStarted(req *ExecutionRequest) {
  487. for _, listener := range req.executor.listeners {
  488. listener.OnExecutionStarted(req.logEntry)
  489. }
  490. }
  491. func appendErrorToStderr(err error, logEntry *InternalLogEntry) {
  492. if err != nil {
  493. logEntry.Output = err.Error() + "\n\n" + logEntry.Output
  494. }
  495. }
  496. type OutputStreamer struct {
  497. Req *ExecutionRequest
  498. output bytes.Buffer
  499. }
  500. func (ost *OutputStreamer) Write(o []byte) (n int, err error) {
  501. for _, listener := range ost.Req.executor.listeners {
  502. listener.OnOutputChunk(o, ost.Req.TrackingID)
  503. }
  504. return ost.output.Write(o)
  505. }
  506. func (ost *OutputStreamer) String() string {
  507. return ost.output.String()
  508. }
  509. func buildEnv(args map[string]string) []string {
  510. ret := append(os.Environ(), "OLIVETIN=1")
  511. for k, v := range args {
  512. varName := fmt.Sprintf("%v", strings.TrimSpace(strings.ToUpper(k)))
  513. // Skip arguments that might not have a name (eg, confirmation), as this causes weird bugs on Windows.
  514. if varName == "" {
  515. continue
  516. }
  517. ret = append(ret, fmt.Sprintf("%v=%v", varName, v))
  518. }
  519. return ret
  520. }
  521. func stepExec(req *ExecutionRequest) bool {
  522. ctx, cancel := context.WithTimeout(context.Background(), time.Duration(req.Binding.Action.Timeout)*time.Second)
  523. defer cancel()
  524. streamer := &OutputStreamer{Req: req}
  525. cmd := buildCommand(ctx, req)
  526. if cmd == nil {
  527. req.logEntry.Output = "Cannot execute: no command arguments provided"
  528. log.Warn("Cannot execute: no command arguments provided")
  529. return false
  530. }
  531. prepareCommand(cmd, streamer, req)
  532. runerr := cmd.Start()
  533. req.logEntry.Process = cmd.Process
  534. waiterr := cmd.Wait()
  535. req.logEntry.ExitCode = int32(cmd.ProcessState.ExitCode())
  536. req.logEntry.Output = streamer.String()
  537. appendErrorToStderr(runerr, req.logEntry)
  538. appendErrorToStderr(waiterr, req.logEntry)
  539. if ctx.Err() == context.DeadlineExceeded {
  540. log.WithFields(log.Fields{
  541. "actionTitle": req.logEntry.ActionTitle,
  542. }).Warnf("Action timed out")
  543. // The context timeout should kill the process, but let's make sure.
  544. err := req.executor.Kill(req.logEntry)
  545. if err != nil {
  546. log.WithFields(log.Fields{
  547. "actionTitle": req.logEntry.ActionTitle,
  548. }).Warnf("could not kill process: %v", err)
  549. }
  550. req.logEntry.TimedOut = true
  551. req.logEntry.Output += "OliveTin::timeout - this action timed out after " + fmt.Sprintf("%v", req.Binding.Action.Timeout) + " seconds. If you need more time for this action, set a longer timeout. See https://docs.olivetin.app/action_customization/timeouts.html for more help."
  552. }
  553. req.logEntry.DatetimeFinished = time.Now()
  554. return true
  555. }
  556. func buildCommand(ctx context.Context, req *ExecutionRequest) *exec.Cmd {
  557. if req.useDirectExec {
  558. return wrapCommandDirect(ctx, req.execArgs)
  559. }
  560. return wrapCommandInShell(ctx, req.finalParsedCommand)
  561. }
  562. func prepareCommand(cmd *exec.Cmd, streamer *OutputStreamer, req *ExecutionRequest) {
  563. cmd.Stdout = streamer
  564. cmd.Stderr = streamer
  565. cmd.Env = buildEnv(req.Arguments)
  566. req.logEntry.ExecutionStarted = true
  567. }
  568. func stepExecAfter(req *ExecutionRequest) bool {
  569. if req.Binding.Action.ShellAfterCompleted == "" {
  570. return true
  571. }
  572. ctx, cancel := context.WithTimeout(context.Background(), time.Duration(req.Binding.Action.Timeout)*time.Second)
  573. defer cancel()
  574. var stdout bytes.Buffer
  575. var stderr bytes.Buffer
  576. args := map[string]string{
  577. "output": req.logEntry.Output,
  578. "exitCode": fmt.Sprintf("%v", req.logEntry.ExitCode),
  579. "ot_executionTrackingId": req.TrackingID,
  580. "ot_username": req.AuthenticatedUser.Username,
  581. }
  582. finalParsedCommand, err := parseCommandForReplacements(req.Binding.Action.ShellAfterCompleted, args, req.Binding.Entity)
  583. if err != nil {
  584. msg := "Could not prepare shellAfterCompleted command: " + err.Error() + "\n"
  585. req.logEntry.Output += msg
  586. log.Warn(msg)
  587. return true
  588. }
  589. cmd := wrapCommandInShell(ctx, finalParsedCommand)
  590. cmd.Stdout = &stdout
  591. cmd.Stderr = &stderr
  592. cmd.Env = buildEnv(args)
  593. runerr := cmd.Start()
  594. waiterr := cmd.Wait()
  595. req.logEntry.Output += "\n"
  596. req.logEntry.Output += "OliveTin::shellAfterCompleted stdout\n"
  597. req.logEntry.Output += stdout.String()
  598. req.logEntry.Output += "OliveTin::shellAfterCompleted stderr\n"
  599. req.logEntry.Output += stderr.String()
  600. req.logEntry.Output += "OliveTin::shellAfterCompleted errors and summary\n"
  601. appendErrorToStderr(runerr, req.logEntry)
  602. appendErrorToStderr(waiterr, req.logEntry)
  603. if ctx.Err() == context.DeadlineExceeded {
  604. req.logEntry.Output += "Your shellAfterCompleted command timed out."
  605. }
  606. req.logEntry.Output += fmt.Sprintf("Your shellAfterCompleted exited with code %v\n", cmd.ProcessState.ExitCode())
  607. req.logEntry.Output += "OliveTin::shellAfterCompleted output complete\n"
  608. return true
  609. }
  610. //gocyclo:ignore
  611. func stepTrigger(req *ExecutionRequest) bool {
  612. if req.Binding.Action.Triggers == nil {
  613. return true
  614. }
  615. if req.TriggerDepth >= MaxTriggerDepth {
  616. log.WithFields(log.Fields{
  617. "actionTitle": req.logEntry.ActionTitle,
  618. "depth": req.TriggerDepth,
  619. }).Warnf("Trigger action reached maximum depth of %v. Not triggering further actions.", MaxTriggerDepth)
  620. req.logEntry.Output += fmt.Sprintf("OliveTin::trigger - this action reached maximum trigger depth of %v. Not triggering further actions.", MaxTriggerDepth)
  621. return true
  622. }
  623. if len(req.Tags) > 0 && req.Tags[0] == "trigger" {
  624. log.Warnf("Trigger action is triggering another trigger action. This is allowed, but be careful not to create trigger loops.")
  625. }
  626. triggerLoop(req)
  627. return true
  628. }
  629. func triggerLoop(req *ExecutionRequest) {
  630. for _, triggerReq := range req.Binding.Action.Triggers {
  631. binding := req.executor.FindBindingByID(triggerReq)
  632. trigger := &ExecutionRequest{
  633. Binding: binding,
  634. TrackingID: uuid.NewString(),
  635. Tags: []string{"trigger"},
  636. AuthenticatedUser: req.AuthenticatedUser,
  637. Arguments: req.Arguments,
  638. Cfg: req.Cfg,
  639. TriggerDepth: req.TriggerDepth + 1,
  640. }
  641. req.executor.ExecRequest(trigger)
  642. }
  643. }
  644. func stepSaveLog(req *ExecutionRequest) bool {
  645. filename := fmt.Sprintf("%v.%v.%v", req.logEntry.ActionTitle, req.logEntry.DatetimeStarted.Unix(), req.logEntry.ExecutionTrackingID)
  646. saveLogResults(req, filename)
  647. saveLogOutput(req, filename)
  648. return true
  649. }
  650. func firstNonEmpty(one, two string) string {
  651. if one != "" {
  652. return one
  653. }
  654. return two
  655. }
  656. func saveLogResults(req *ExecutionRequest, filename string) {
  657. dir := firstNonEmpty(req.Binding.Action.SaveLogs.ResultsDirectory, req.Cfg.SaveLogs.ResultsDirectory)
  658. if dir != "" {
  659. data, err := yaml.Marshal(req.logEntry)
  660. if err != nil {
  661. log.Warnf("%v", err)
  662. }
  663. filepath := path.Join(dir, filename+".yaml")
  664. err = os.WriteFile(filepath, data, 0644)
  665. if err != nil {
  666. log.Warnf("%v", err)
  667. }
  668. }
  669. }
  670. func saveLogOutput(req *ExecutionRequest, filename string) {
  671. dir := firstNonEmpty(req.Binding.Action.SaveLogs.OutputDirectory, req.Cfg.SaveLogs.OutputDirectory)
  672. if dir != "" {
  673. data := req.logEntry.Output
  674. filepath := path.Join(dir, filename+".log")
  675. err := os.WriteFile(filepath, []byte(data), 0644)
  676. if err != nil {
  677. log.Warnf("%v", err)
  678. }
  679. }
  680. }